diff --git a/src/Compilation.zig b/src/Compilation.zig index c1d6ef70c8..fdb641e6d5 100644 --- a/src/Compilation.zig +++ b/src/Compilation.zig @@ -2262,8 +2262,6 @@ pub fn update(comp: *Compilation, main_progress_node: std.Progress.Node) !void { const pt: Zcu.PerThread = .activate(zcu, .main); defer pt.deactivate(); - zcu.compile_log_text.shrinkAndFree(gpa, 0); - zcu.skip_analysis_this_update = false; // Make sure std.zig is inside the import_table. We unconditionally need @@ -3323,30 +3321,15 @@ pub fn getAllErrorsAlloc(comp: *Compilation) !ErrorBundle { err: *?Error, const Error = @typeInfo( - @typeInfo(@TypeOf(Zcu.SrcLoc.span)).@"fn".return_type.?, + @typeInfo(@TypeOf(Zcu.LazySrcLoc.lessThan)).@"fn".return_type.?, ).error_union.error_set; pub fn lessThan(ctx: @This(), lhs_index: usize, rhs_index: usize) bool { - if (ctx.err.*) |_| return lhs_index < rhs_index; - const lhs_src_loc = ctx.errors[lhs_index].src_loc.upgradeOrLost(ctx.zcu) orelse { - // LHS source location lost, so should never be referenced. Just sort it to the end. - return false; - }; - const rhs_src_loc = ctx.errors[rhs_index].src_loc.upgradeOrLost(ctx.zcu) orelse { - // RHS source location lost, so should never be referenced. Just sort it to the end. - return true; - }; - return if (lhs_src_loc.file_scope != rhs_src_loc.file_scope) std.mem.order( - u8, - lhs_src_loc.file_scope.sub_file_path, - rhs_src_loc.file_scope.sub_file_path, - ).compare(.lt) else (lhs_src_loc.span(ctx.zcu.gpa) catch |e| { + if (ctx.err.* != null) return lhs_index < rhs_index; + return ctx.errors[lhs_index].src_loc.lessThan(ctx.errors[rhs_index].src_loc, ctx.zcu) catch |e| { ctx.err.* = e; return lhs_index < rhs_index; - }).main < (rhs_src_loc.span(ctx.zcu.gpa) catch |e| { - ctx.err.* = e; - return lhs_index < rhs_index; - }).main; + }; } }; @@ -3450,28 +3433,76 @@ pub fn getAllErrorsAlloc(comp: *Compilation) !ErrorBundle { try comp.link_diags.addMessagesToBundle(&bundle, comp.bin_file); - if (comp.zcu) |zcu| { - if (!zcu.skip_analysis_this_update and bundle.root_list.items.len == 0 and zcu.compile_log_sources.count() != 0) { - const values = zcu.compile_log_sources.values(); - // First one will be the error; subsequent ones will be notes. - const src_loc = values[0].src(); - const err_msg: Zcu.ErrorMsg = .{ - .src_loc = src_loc, - .msg = "found compile log statement", - .notes = try gpa.alloc(Zcu.ErrorMsg, zcu.compile_log_sources.count() - 1), - }; - defer gpa.free(err_msg.notes); + const compile_log_text: []const u8 = compile_log_text: { + const zcu = comp.zcu orelse break :compile_log_text ""; + if (zcu.skip_analysis_this_update) break :compile_log_text ""; + if (zcu.compile_logs.count() == 0) break :compile_log_text ""; - for (values[1..], err_msg.notes) |src_info, *note| { - note.* = .{ - .src_loc = src_info.src(), - .msg = "also here", + // If there are no other errors, we include a "found compile log statement" error. + // Otherwise, we just show the compile log output, with no error. + const include_compile_log_sources = bundle.root_list.items.len == 0; + + const refs = try zcu.resolveReferences(); + + var messages: std.ArrayListUnmanaged(Zcu.ErrorMsg) = .empty; + defer messages.deinit(gpa); + for (zcu.compile_logs.keys(), zcu.compile_logs.values()) |logging_unit, compile_log| { + if (!refs.contains(logging_unit)) continue; + try messages.append(gpa, .{ + .src_loc = compile_log.src(), + .msg = undefined, // populated later + .notes = &.{}, + // We actually clear this later for most of these, but we populate + // this field for now to avoid having to allocate more data to track + // which compile log text this corresponds to. + .reference_trace_root = logging_unit.toOptional(), + }); + } + + if (messages.items.len == 0) break :compile_log_text ""; + + // Okay, there *are* referenced compile logs. Sort them into a consistent order. + + const SortContext = struct { + err: *?Error, + zcu: *Zcu, + const Error = @typeInfo( + @typeInfo(@TypeOf(Zcu.LazySrcLoc.lessThan)).@"fn".return_type.?, + ).error_union.error_set; + fn lessThan(ctx: @This(), lhs: Zcu.ErrorMsg, rhs: Zcu.ErrorMsg) bool { + if (ctx.err.* != null) return false; + return lhs.src_loc.lessThan(rhs.src_loc, ctx.zcu) catch |e| { + ctx.err.* = e; + return false; }; } + }; + var sort_err: ?SortContext.Error = null; + std.mem.sort(Zcu.ErrorMsg, messages.items, @as(SortContext, .{ .err = &sort_err, .zcu = zcu }), SortContext.lessThan); + if (sort_err) |e| return e; - try addModuleErrorMsg(zcu, &bundle, err_msg); + var log_text: std.ArrayListUnmanaged(u8) = .empty; + defer log_text.deinit(gpa); + + // Index 0 will be the root message; the rest will be notes. + // Only the actual message, i.e. index 0, will retain its reference trace. + try appendCompileLogLines(&log_text, zcu, messages.items[0].reference_trace_root.unwrap().?); + messages.items[0].notes = messages.items[1..]; + messages.items[0].msg = "found compile log statement"; + for (messages.items[1..]) |*note| { + try appendCompileLogLines(&log_text, zcu, note.reference_trace_root.unwrap().?); + note.reference_trace_root = .none; // notes don't have reference traces + note.msg = "also here"; } - } + + // We don't actually include the error here if `!include_compile_log_sources`. + // The sorting above was still necessary, though, to get `log_text` in the right order. + if (include_compile_log_sources) { + try addModuleErrorMsg(zcu, &bundle, messages.items[0]); + } + + break :compile_log_text try log_text.toOwnedSlice(gpa); + }; // TODO: eventually, this should be behind `std.debug.runtime_safety`. But right now, this is a // very common way for incremental compilation bugs to manifest, so let's always check it. @@ -3497,10 +3528,24 @@ pub fn getAllErrorsAlloc(comp: *Compilation) !ErrorBundle { } }; - const compile_log_text = if (comp.zcu) |m| m.compile_log_text.items else ""; return bundle.toOwnedBundle(compile_log_text); } +/// Writes all compile log lines belonging to `logging_unit` into `log_text` using `zcu.gpa`. +fn appendCompileLogLines(log_text: *std.ArrayListUnmanaged(u8), zcu: *Zcu, logging_unit: InternPool.AnalUnit) Allocator.Error!void { + const gpa = zcu.gpa; + const ip = &zcu.intern_pool; + var opt_line_idx = zcu.compile_logs.get(logging_unit).?.first_line.toOptional(); + while (opt_line_idx.unwrap()) |line_idx| { + const line = line_idx.get(zcu).*; + opt_line_idx = line.next; + const line_slice = line.data.toSlice(ip); + try log_text.ensureUnusedCapacity(gpa, line_slice.len + 1); + log_text.appendSliceAssumeCapacity(line_slice); + log_text.appendAssumeCapacity('\n'); + } +} + fn anyErrors(comp: *Compilation) bool { return (totalErrorCount(comp) catch return true) != 0; } diff --git a/src/Sema.zig b/src/Sema.zig index 5dbf26f375..7d7d275e9b 100644 --- a/src/Sema.zig +++ b/src/Sema.zig @@ -5884,10 +5884,12 @@ fn zirCompileLog( ) CompileError!Air.Inst.Ref { const pt = sema.pt; const zcu = pt.zcu; + const gpa = zcu.gpa; - var managed = zcu.compile_log_text.toManaged(sema.gpa); - defer pt.zcu.compile_log_text = managed.moveToUnmanaged(); - const writer = managed.writer(); + var buf: std.ArrayListUnmanaged(u8) = .empty; + defer buf.deinit(gpa); + + const writer = buf.writer(gpa); const extra = sema.code.extraData(Zir.Inst.NodeMultiOp, extended.operand); const src_node = extra.data.src_node; @@ -5906,13 +5908,37 @@ fn zirCompileLog( try writer.print("@as({}, [runtime value])", .{arg_ty.fmt(pt)}); } } - try writer.print("\n", .{}); - const gop = try zcu.compile_log_sources.getOrPut(sema.gpa, sema.owner); - if (!gop.found_existing) gop.value_ptr.* = .{ - .base_node_inst = block.src_base_inst, - .node_offset = src_node, + const line_data = try zcu.intern_pool.getOrPutString(gpa, pt.tid, buf.items, .no_embedded_nulls); + + const line_idx: Zcu.CompileLogLine.Index = if (zcu.free_compile_log_lines.pop()) |idx| idx: { + zcu.compile_log_lines.items[@intFromEnum(idx)] = .{ + .next = .none, + .data = line_data, + }; + break :idx idx; + } else idx: { + try zcu.compile_log_lines.append(gpa, .{ + .next = .none, + .data = line_data, + }); + break :idx @enumFromInt(zcu.compile_log_lines.items.len - 1); }; + + const gop = try zcu.compile_logs.getOrPut(gpa, sema.owner); + if (gop.found_existing) { + const prev_line = gop.value_ptr.last_line.get(zcu); + assert(prev_line.next == .none); + prev_line.next = line_idx.toOptional(); + gop.value_ptr.last_line = line_idx; + } else { + gop.value_ptr.* = .{ + .base_node_inst = block.src_base_inst, + .node_offset = src_node, + .first_line = line_idx, + .last_line = line_idx, + }; + } return .void_value; } diff --git a/src/Zcu.zig b/src/Zcu.zig index 1486be6746..f9fbe0b652 100644 --- a/src/Zcu.zig +++ b/src/Zcu.zig @@ -130,18 +130,23 @@ transitive_failed_analysis: std.AutoArrayHashMapUnmanaged(AnalUnit, void) = .emp /// The ErrorMsg memory is owned by the `AnalUnit`, using Module's general purpose allocator. failed_codegen: std.AutoArrayHashMapUnmanaged(InternPool.Nav.Index, *ErrorMsg) = .empty, failed_types: std.AutoArrayHashMapUnmanaged(InternPool.Index, *ErrorMsg) = .empty, -/// Keep track of one `@compileLog` callsite per `AnalUnit`. -/// The value is the source location of the `@compileLog` call, convertible to a `LazySrcLoc`. -compile_log_sources: std.AutoArrayHashMapUnmanaged(AnalUnit, extern struct { +/// Keep track of `@compileLog`s per `AnalUnit`. +/// We track the source location of the first `@compileLog` call, and all logged lines as a linked list. +/// The list is singly linked, but we do track its tail for fast appends (optimizing many logs in one unit). +compile_logs: std.AutoArrayHashMapUnmanaged(AnalUnit, extern struct { base_node_inst: InternPool.TrackedInst.Index, node_offset: Ast.Node.Offset, + first_line: CompileLogLine.Index, + last_line: CompileLogLine.Index, pub fn src(self: @This()) LazySrcLoc { return .{ .base_node_inst = self.base_node_inst, .offset = LazySrcLoc.Offset.nodeOffset(self.node_offset), }; } -}) = .{}, +}) = .empty, +compile_log_lines: std.ArrayListUnmanaged(CompileLogLine) = .empty, +free_compile_log_lines: std.ArrayListUnmanaged(CompileLogLine.Index) = .empty, /// Using a map here for consistency with the other fields here. /// The ErrorMsg memory is owned by the `File`, using Module's general purpose allocator. failed_files: std.AutoArrayHashMapUnmanaged(*File, ?*ErrorMsg) = .empty, @@ -196,8 +201,6 @@ stage1_flags: packed struct { reserved: u2 = 0, } = .{}, -compile_log_text: std.ArrayListUnmanaged(u8) = .empty, - test_functions: std.AutoArrayHashMapUnmanaged(InternPool.Nav.Index, void) = .empty, global_assembly: std.AutoArrayHashMapUnmanaged(AnalUnit, []u8) = .empty, @@ -547,6 +550,31 @@ pub const Export = struct { }; }; +pub const CompileLogLine = struct { + next: Index.Optional, + /// Does *not* include the trailing newline. + data: InternPool.NullTerminatedString, + pub const Index = enum(u32) { + _, + pub fn get(idx: Index, zcu: *Zcu) *CompileLogLine { + return &zcu.compile_log_lines.items[@intFromEnum(idx)]; + } + pub fn toOptional(idx: Index) Optional { + return @enumFromInt(@intFromEnum(idx)); + } + pub const Optional = enum(u32) { + none = std.math.maxInt(u32), + _, + pub fn unwrap(opt: Optional) ?Index { + return switch (opt) { + .none => null, + _ => @enumFromInt(@intFromEnum(opt)), + }; + } + }; + }; +}; + pub const Reference = struct { /// The `AnalUnit` whose semantic analysis was triggered by this reference. referenced: AnalUnit, @@ -2464,6 +2492,30 @@ pub const LazySrcLoc = struct { .lazy = lazy.offset, }; } + + /// Used to sort error messages, so that they're printed in a consistent order. + /// If an error is returned, that error makes sorting impossible. + pub fn lessThan(lhs_lazy: LazySrcLoc, rhs_lazy: LazySrcLoc, zcu: *Zcu) !bool { + const lhs_src = lhs_lazy.upgradeOrLost(zcu) orelse { + // LHS source location lost, so should never be referenced. Just sort it to the end. + return false; + }; + const rhs_src = rhs_lazy.upgradeOrLost(zcu) orelse { + // RHS source location lost, so should never be referenced. Just sort it to the end. + return true; + }; + if (lhs_src.file_scope != rhs_src.file_scope) { + return std.mem.order( + u8, + lhs_src.file_scope.sub_file_path, + rhs_src.file_scope.sub_file_path, + ).compare(.lt); + } + + const lhs_span = try lhs_src.span(zcu.gpa); + const rhs_span = try rhs_src.span(zcu.gpa); + return lhs_span.main < rhs_span.main; + } }; pub const SemaError = error{ OutOfMemory, AnalysisFail }; @@ -2506,8 +2558,6 @@ pub fn deinit(zcu: *Zcu) void { } zcu.embed_table.deinit(gpa); - zcu.compile_log_text.deinit(gpa); - zcu.local_zir_cache.handle.close(); zcu.global_zir_cache.handle.close(); @@ -2535,7 +2585,9 @@ pub fn deinit(zcu: *Zcu) void { } zcu.cimport_errors.deinit(gpa); - zcu.compile_log_sources.deinit(gpa); + zcu.compile_logs.deinit(gpa); + zcu.compile_log_lines.deinit(gpa); + zcu.free_compile_log_lines.deinit(gpa); zcu.all_exports.deinit(gpa); zcu.free_exports.deinit(gpa); @@ -3412,6 +3464,22 @@ pub fn deleteUnitReferences(zcu: *Zcu, anal_unit: AnalUnit) void { } } +/// Delete all compile logs performed by this `AnalUnit`. +/// Re-analysis of the `AnalUnit` will cause logs to be rediscovered. +pub fn deleteUnitCompileLogs(zcu: *Zcu, anal_unit: AnalUnit) void { + const kv = zcu.compile_logs.fetchSwapRemove(anal_unit) orelse return; + const gpa = zcu.gpa; + var opt_line_idx = kv.value.first_line.toOptional(); + while (opt_line_idx.unwrap()) |line_idx| { + zcu.free_compile_log_lines.append(gpa, line_idx) catch { + // This space will be reused eventually, so we need not propagate this error. + // Just leak it for now, and let GC reclaim it later on. + return; + }; + opt_line_idx = line_idx.get(zcu).next; + } +} + pub fn addUnitReference(zcu: *Zcu, src_unit: AnalUnit, referenced_unit: AnalUnit, ref_src: LazySrcLoc) Allocator.Error!void { const gpa = zcu.gpa; diff --git a/src/Zcu/PerThread.zig b/src/Zcu/PerThread.zig index 9084e8b0ca..c80b80cb7d 100644 --- a/src/Zcu/PerThread.zig +++ b/src/Zcu/PerThread.zig @@ -599,6 +599,7 @@ pub fn ensureMemoizedStateUpToDate(pt: Zcu.PerThread, stage: InternPool.Memoized _ = zcu.outdated_ready.swapRemove(unit); // No need for `deleteUnitExports` because we never export anything. zcu.deleteUnitReferences(unit); + zcu.deleteUnitCompileLogs(unit); if (zcu.failed_analysis.fetchSwapRemove(unit)) |kv| { kv.value.destroy(gpa); } @@ -749,6 +750,7 @@ pub fn ensureComptimeUnitUpToDate(pt: Zcu.PerThread, cu_id: InternPool.ComptimeU if (dev.env.supports(.incremental)) { zcu.deleteUnitExports(anal_unit); zcu.deleteUnitReferences(anal_unit); + zcu.deleteUnitCompileLogs(anal_unit); if (zcu.failed_analysis.fetchSwapRemove(anal_unit)) |kv| { kv.value.destroy(gpa); } @@ -921,6 +923,7 @@ pub fn ensureNavValUpToDate(pt: Zcu.PerThread, nav_id: InternPool.Nav.Index) Zcu _ = zcu.outdated_ready.swapRemove(anal_unit); zcu.deleteUnitExports(anal_unit); zcu.deleteUnitReferences(anal_unit); + zcu.deleteUnitCompileLogs(anal_unit); if (zcu.failed_analysis.fetchSwapRemove(anal_unit)) |kv| { kv.value.destroy(gpa); } @@ -1293,6 +1296,7 @@ pub fn ensureNavTypeUpToDate(pt: Zcu.PerThread, nav_id: InternPool.Nav.Index) Zc _ = zcu.outdated_ready.swapRemove(anal_unit); zcu.deleteUnitExports(anal_unit); zcu.deleteUnitReferences(anal_unit); + zcu.deleteUnitCompileLogs(anal_unit); if (zcu.failed_analysis.fetchSwapRemove(anal_unit)) |kv| { kv.value.destroy(gpa); } @@ -1527,6 +1531,7 @@ pub fn ensureFuncBodyUpToDate(pt: Zcu.PerThread, maybe_coerced_func_index: Inter _ = zcu.outdated_ready.swapRemove(anal_unit); zcu.deleteUnitExports(anal_unit); zcu.deleteUnitReferences(anal_unit); + zcu.deleteUnitCompileLogs(anal_unit); if (zcu.failed_analysis.fetchSwapRemove(anal_unit)) |kv| { kv.value.destroy(gpa); } @@ -3764,6 +3769,7 @@ pub fn ensureTypeUpToDate(pt: Zcu.PerThread, ty: InternPool.Index) Zcu.SemaError // reusing the memory which is currently being used to track this state. zcu.deleteUnitExports(anal_unit); zcu.deleteUnitReferences(anal_unit); + zcu.deleteUnitCompileLogs(anal_unit); if (zcu.failed_analysis.fetchSwapRemove(anal_unit)) |kv| { kv.value.destroy(gpa); } diff --git a/test/incremental/compile_error_then_log b/test/incremental/compile_error_then_log index 800fb92dfe..5a6340f9eb 100644 --- a/test/incremental/compile_error_then_log +++ b/test/incremental/compile_error_then_log @@ -12,6 +12,7 @@ comptime { @compileLog("this is a log"); } #expect_error=main.zig:3:5: error: this is an error +#expect_compile_log=@as(*const [13:0]u8, "this is a log") #update=remove the compile error #file=main.zig @@ -23,3 +24,4 @@ comptime { @compileLog("this is a log"); } #expect_error=main.zig:6:5: error: found compile log statement +#expect_compile_log=@as(*const [13:0]u8, "this is a log") diff --git a/test/incremental/compile_log b/test/incremental/compile_log new file mode 100644 index 0000000000..f7fa8ff7e1 --- /dev/null +++ b/test/incremental/compile_log @@ -0,0 +1,30 @@ +#target=x86_64-linux-selfhosted +#target=x86_64-linux-cbe +#target=x86_64-windows-cbe +#target=wasm32-wasi-selfhosted + +#update=initial version with no compile log +#file=main.zig +const std = @import("std"); +pub fn main() !void { + try std.io.getStdOut().writeAll("Hello, World!\n"); +} +#expect_stdout="Hello, World!\n" + +#update=add compile log +#file=main.zig +const std = @import("std"); +pub fn main() !void { + try std.io.getStdOut().writeAll("Hello, World!\n"); + @compileLog("this is a log"); +} +#expect_error=main.zig:4:5: error: found compile log statement +#expect_compile_log=@as(*const [13:0]u8, "this is a log") + +#update=remove compile log +#file=main.zig +const std = @import("std"); +pub fn main() !void { + try std.io.getStdOut().writeAll("Hello, World!\n"); +} +#expect_stdout="Hello, World!\n" diff --git a/tools/incr-check.zig b/tools/incr-check.zig index 639d497256..d5eb2b2876 100644 --- a/tools/incr-check.zig +++ b/tools/incr-check.zig @@ -341,9 +341,9 @@ const Eval = struct { } fn checkErrorOutcome(eval: *Eval, update: Case.Update, error_bundle: std.zig.ErrorBundle) !void { - const expected_errors = switch (update.outcome) { + const expected = switch (update.outcome) { .unknown => return, - .compile_errors => |expected_errors| expected_errors, + .compile_errors => |ce| ce, .stdout, .exit_code => { const color: std.zig.Color = .auto; error_bundle.renderToStdErr(color.renderOptions()); @@ -354,24 +354,30 @@ const Eval = struct { var expected_idx: usize = 0; for (error_bundle.getMessages()) |err_idx| { - if (expected_idx == expected_errors.len) { + if (expected_idx == expected.errors.len) { const color: std.zig.Color = .auto; error_bundle.renderToStdErr(color.renderOptions()); eval.fatal("update '{s}': more errors than expected", .{update.name}); } - eval.checkOneError(update, error_bundle, expected_errors[expected_idx], false, err_idx); + eval.checkOneError(update, error_bundle, expected.errors[expected_idx], false, err_idx); expected_idx += 1; for (error_bundle.getNotes(err_idx)) |note_idx| { - if (expected_idx == expected_errors.len) { + if (expected_idx == expected.errors.len) { const color: std.zig.Color = .auto; error_bundle.renderToStdErr(color.renderOptions()); eval.fatal("update '{s}': more error notes than expected", .{update.name}); } - eval.checkOneError(update, error_bundle, expected_errors[expected_idx], true, note_idx); + eval.checkOneError(update, error_bundle, expected.errors[expected_idx], true, note_idx); expected_idx += 1; } } + + if (!std.mem.eql(u8, error_bundle.getCompileLogOutput(), expected.compile_log_output)) { + const color: std.zig.Color = .auto; + error_bundle.renderToStdErr(color.renderOptions()); + eval.fatal("update '{s}': unexpected compile log output", .{update.name}); + } } fn checkOneError( @@ -634,7 +640,10 @@ const Case = struct { const Outcome = union(enum) { unknown, - compile_errors: []const ExpectedError, + compile_errors: struct { + errors: []const ExpectedError, + compile_log_output: []const u8, + }, stdout: []const u8, exit_code: u8, }; @@ -759,7 +768,29 @@ const Case = struct { try errors.append(arena, parseExpectedError(new_val, line_n)); } - last_update.outcome = .{ .compile_errors = errors.items }; + var compile_log_output: std.ArrayListUnmanaged(u8) = .empty; + while (true) { + const next_line = it.peek() orelse break; + if (!std.mem.startsWith(u8, next_line, "#")) break; + var new_line_it = std.mem.splitScalar(u8, next_line, '='); + const new_key = new_line_it.first()[1..]; + const new_val = std.mem.trimRight(u8, new_line_it.rest(), "\r"); + if (new_val.len == 0) break; + if (!std.mem.eql(u8, new_key, "expect_compile_log")) break; + + _ = it.next(); + line_n += 1; + try compile_log_output.ensureUnusedCapacity(arena, new_val.len + 1); + compile_log_output.appendSliceAssumeCapacity(new_val); + compile_log_output.appendAssumeCapacity('\n'); + } + + last_update.outcome = .{ .compile_errors = .{ + .errors = errors.items, + .compile_log_output = compile_log_output.items, + } }; + } else if (std.mem.eql(u8, key, "expect_compile_log")) { + fatal("line {d}: 'expect_compile_log' must immediately follow 'expect_error'", .{line_n}); } else { fatal("line {d}: unrecognized key '{s}'", .{ line_n, key }); }