authorgravatar for andrew@ziglang.orgAndrew Kelley <andrew@ziglang.org> 2023-12-03 14:12:17-07:00
committergravatar for andrew@ziglang.orgAndrew Kelley <andrew@ziglang.org> 2024-01-01 17:51:18-07:00
log0ee8fbb15dd32a2bb91696e4765926e9170d2a23
treee34aa6718abbb40e54e93e759d02cda90168a4d5
parentad385649b985c53ddec530c627dccbe30c0ce0a6

build runner: print subtree of failed nodes context

Previously when an error message is printed, it is sometimes not possible to know which build step it corresponds to. With the subtree printed in this commit, the context is always clear.

1 files changed, 185 insertions(+), 137 deletions(-)

lib/build_runner.zig+185-137
...@@ -363,7 +363,7 @@ const Run = struct {...@@ -363,7 +363,7 @@ const Run = struct {
363 claimed_rss: usize,363 claimed_rss: usize,
364 summary: ?Summary,364 summary: ?Summary,
365 ttyconf: std.io.tty.Config,365 ttyconf: std.io.tty.Config,
366 stderr: std.fs.File,366 stderr: File,
367};367};
368368
369fn runStepNames(369fn runStepNames(
...@@ -584,7 +584,7 @@ const PrintNode = struct {...@@ -584,7 +584,7 @@ const PrintNode = struct {
584 last: bool = false,584 last: bool = false,
585};585};
586586
587fn printPrefix(node: *PrintNode, stderr: std.fs.File, ttyconf: std.io.tty.Config) !void {587fn printPrefix(node: *PrintNode, stderr: File, ttyconf: std.io.tty.Config) !void {
588 const parent = node.parent orelse return;588 const parent = node.parent orelse return;
589 if (parent.parent == null) return;589 if (parent.parent == null) return;
590 try printPrefix(parent, stderr, ttyconf);590 try printPrefix(parent, stderr, ttyconf);
...@@ -598,11 +598,145 @@ fn printPrefix(node: *PrintNode, stderr: std.fs.File, ttyconf: std.io.tty.Config...@@ -598,11 +598,145 @@ fn printPrefix(node: *PrintNode, stderr: std.fs.File, ttyconf: std.io.tty.Config
598 }598 }
599}599}
600600
601fn printChildNodePrefix(stderr: File, ttyconf: std.io.tty.Config) !void {
602 try stderr.writeAll(switch (ttyconf) {
603 .no_color, .windows_api => "+- ",
604 .escape_codes => "\x1B\x28\x30\x6d\x71\x1B\x28\x42 ", // └─
605 });
606}
607
608fn printStepStatus(
609 s: *Step,
610 stderr: File,
611 ttyconf: std.io.tty.Config,
612 run: *const Run,
613) !void {
614 switch (s.state) {
615 .precheck_unstarted => unreachable,
616 .precheck_started => unreachable,
617 .precheck_done => unreachable,
618 .running => unreachable,
619
620 .dependency_failure => {
621 try ttyconf.setColor(stderr, .dim);
622 try stderr.writeAll(" transitive failure\n");
623 try ttyconf.setColor(stderr, .reset);
624 },
625
626 .success => {
627 try ttyconf.setColor(stderr, .green);
628 if (s.result_cached) {
629 try stderr.writeAll(" cached");
630 } else if (s.test_results.test_count > 0) {
631 const pass_count = s.test_results.passCount();
632 try stderr.writer().print(" {d} passed", .{pass_count});
633 if (s.test_results.skip_count > 0) {
634 try ttyconf.setColor(stderr, .yellow);
635 try stderr.writer().print(" {d} skipped", .{s.test_results.skip_count});
636 }
637 } else {
638 try stderr.writeAll(" success");
639 }
640 try ttyconf.setColor(stderr, .reset);
641 if (s.result_duration_ns) |ns| {
642 try ttyconf.setColor(stderr, .dim);
643 if (ns >= std.time.ns_per_min) {
644 try stderr.writer().print(" {d}m", .{ns / std.time.ns_per_min});
645 } else if (ns >= std.time.ns_per_s) {
646 try stderr.writer().print(" {d}s", .{ns / std.time.ns_per_s});
647 } else if (ns >= std.time.ns_per_ms) {
648 try stderr.writer().print(" {d}ms", .{ns / std.time.ns_per_ms});
649 } else if (ns >= std.time.ns_per_us) {
650 try stderr.writer().print(" {d}us", .{ns / std.time.ns_per_us});
651 } else {
652 try stderr.writer().print(" {d}ns", .{ns});
653 }
654 try ttyconf.setColor(stderr, .reset);
655 }
656 if (s.result_peak_rss != 0) {
657 const rss = s.result_peak_rss;
658 try ttyconf.setColor(stderr, .dim);
659 if (rss >= 1000_000_000) {
660 try stderr.writer().print(" MaxRSS:{d}G", .{rss / 1000_000_000});
661 } else if (rss >= 1000_000) {
662 try stderr.writer().print(" MaxRSS:{d}M", .{rss / 1000_000});
663 } else if (rss >= 1000) {
664 try stderr.writer().print(" MaxRSS:{d}K", .{rss / 1000});
665 } else {
666 try stderr.writer().print(" MaxRSS:{d}B", .{rss});
667 }
668 try ttyconf.setColor(stderr, .reset);
669 }
670 try stderr.writeAll("\n");
671 },
672 .skipped, .skipped_oom => |skip| {
673 try ttyconf.setColor(stderr, .yellow);
674 try stderr.writeAll(" skipped");
675 if (skip == .skipped_oom) {
676 try stderr.writeAll(" (not enough memory)");
677 try ttyconf.setColor(stderr, .dim);
678 try stderr.writer().print(" upper bound of {d} exceeded runner limit ({d})", .{ s.max_rss, run.max_rss });
679 try ttyconf.setColor(stderr, .yellow);
680 }
681 try stderr.writeAll("\n");
682 try ttyconf.setColor(stderr, .reset);
683 },
684 .failure => try printStepFailure(s, stderr, ttyconf),
685 }
686}
687
688fn printStepFailure(
689 s: *Step,
690 stderr: File,
691 ttyconf: std.io.tty.Config,
692) !void {
693 if (s.result_error_bundle.errorMessageCount() > 0) {
694 try ttyconf.setColor(stderr, .red);
695 try stderr.writer().print(" {d} errors\n", .{
696 s.result_error_bundle.errorMessageCount(),
697 });
698 try ttyconf.setColor(stderr, .reset);
699 } else if (!s.test_results.isSuccess()) {
700 try stderr.writer().print(" {d}/{d} passed", .{
701 s.test_results.passCount(), s.test_results.test_count,
702 });
703 if (s.test_results.fail_count > 0) {
704 try stderr.writeAll(", ");
705 try ttyconf.setColor(stderr, .red);
706 try stderr.writer().print("{d} failed", .{
707 s.test_results.fail_count,
708 });
709 try ttyconf.setColor(stderr, .reset);
710 }
711 if (s.test_results.skip_count > 0) {
712 try stderr.writeAll(", ");
713 try ttyconf.setColor(stderr, .yellow);
714 try stderr.writer().print("{d} skipped", .{
715 s.test_results.skip_count,
716 });
717 try ttyconf.setColor(stderr, .reset);
718 }
719 if (s.test_results.leak_count > 0) {
720 try stderr.writeAll(", ");
721 try ttyconf.setColor(stderr, .red);
722 try stderr.writer().print("{d} leaked", .{
723 s.test_results.leak_count,
724 });
725 try ttyconf.setColor(stderr, .reset);
726 }
727 try stderr.writeAll("\n");
728 } else {
729 try ttyconf.setColor(stderr, .red);
730 try stderr.writeAll(" failure\n");
731 try ttyconf.setColor(stderr, .reset);
732 }
733}
734
601fn printTreeStep(735fn printTreeStep(
602 b: *std.Build,736 b: *std.Build,
603 s: *Step,737 s: *Step,
604 run: *const Run,738 run: *const Run,
605 stderr: std.fs.File,739 stderr: File,
606 ttyconf: std.io.tty.Config,740 ttyconf: std.io.tty.Config,
607 parent_node: *PrintNode,741 parent_node: *PrintNode,
608 step_stack: *std.AutoArrayHashMapUnmanaged(*Step, void),742 step_stack: *std.AutoArrayHashMapUnmanaged(*Step, void),
...@@ -615,10 +749,7 @@ fn printTreeStep(...@@ -615,10 +749,7 @@ fn printTreeStep(
615 if (!first) try ttyconf.setColor(stderr, .dim);749 if (!first) try ttyconf.setColor(stderr, .dim);
616 if (parent_node.parent != null) {750 if (parent_node.parent != null) {
617 if (parent_node.last) {751 if (parent_node.last) {
618 try stderr.writeAll(switch (ttyconf) {752 try printChildNodePrefix(stderr, ttyconf);
619 .no_color, .windows_api => "+- ",
620 .escape_codes => "\x1B\x28\x30\x6d\x71\x1B\x28\x42 ", // └─
621 });
622 } else {753 } else {
623 try stderr.writeAll(switch (ttyconf) {754 try stderr.writeAll(switch (ttyconf) {
624 .no_color, .windows_api => "+- ",755 .no_color, .windows_api => "+- ",
...@@ -631,119 +762,7 @@ fn printTreeStep(...@@ -631,119 +762,7 @@ fn printTreeStep(
631 try stderr.writeAll(s.name);762 try stderr.writeAll(s.name);
632763
633 if (first) {764 if (first) {
634 switch (s.state) {765 try printStepStatus(s, stderr, ttyconf, run);
635 .precheck_unstarted => unreachable,
636 .precheck_started => unreachable,
637 .precheck_done => unreachable,
638 .running => unreachable,
639
640 .dependency_failure => {
641 try ttyconf.setColor(stderr, .dim);
642 try stderr.writeAll(" transitive failure\n");
643 try ttyconf.setColor(stderr, .reset);
644 },
645
646 .success => {
647 try ttyconf.setColor(stderr, .green);
648 if (s.result_cached) {
649 try stderr.writeAll(" cached");
650 } else if (s.test_results.test_count > 0) {
651 const pass_count = s.test_results.passCount();
652 try stderr.writer().print(" {d} passed", .{pass_count});
653 if (s.test_results.skip_count > 0) {
654 try ttyconf.setColor(stderr, .yellow);
655 try stderr.writer().print(" {d} skipped", .{s.test_results.skip_count});
656 }
657 } else {
658 try stderr.writeAll(" success");
659 }
660 try ttyconf.setColor(stderr, .reset);
661 if (s.result_duration_ns) |ns| {
662 try ttyconf.setColor(stderr, .dim);
663 if (ns >= std.time.ns_per_min) {
664 try stderr.writer().print(" {d}m", .{ns / std.time.ns_per_min});
665 } else if (ns >= std.time.ns_per_s) {
666 try stderr.writer().print(" {d}s", .{ns / std.time.ns_per_s});
667 } else if (ns >= std.time.ns_per_ms) {
668 try stderr.writer().print(" {d}ms", .{ns / std.time.ns_per_ms});
669 } else if (ns >= std.time.ns_per_us) {
670 try stderr.writer().print(" {d}us", .{ns / std.time.ns_per_us});
671 } else {
672 try stderr.writer().print(" {d}ns", .{ns});
673 }
674 try ttyconf.setColor(stderr, .reset);
675 }
676 if (s.result_peak_rss != 0) {
677 const rss = s.result_peak_rss;
678 try ttyconf.setColor(stderr, .dim);
679 if (rss >= 1000_000_000) {
680 try stderr.writer().print(" MaxRSS:{d}G", .{rss / 1000_000_000});
681 } else if (rss >= 1000_000) {
682 try stderr.writer().print(" MaxRSS:{d}M", .{rss / 1000_000});
683 } else if (rss >= 1000) {
684 try stderr.writer().print(" MaxRSS:{d}K", .{rss / 1000});
685 } else {
686 try stderr.writer().print(" MaxRSS:{d}B", .{rss});
687 }
688 try ttyconf.setColor(stderr, .reset);
689 }
690 try stderr.writeAll("\n");
691 },
692 .skipped, .skipped_oom => |skip| {
693 try ttyconf.setColor(stderr, .yellow);
694 try stderr.writeAll(" skipped");
695 if (skip == .skipped_oom) {
696 try stderr.writeAll(" (not enough memory)");
697 try ttyconf.setColor(stderr, .dim);
698 try stderr.writer().print(" upper bound of {d} exceeded runner limit ({d})", .{ s.max_rss, run.max_rss });
699 try ttyconf.setColor(stderr, .yellow);
700 }
701 try stderr.writeAll("\n");
702 try ttyconf.setColor(stderr, .reset);
703 },
704 .failure => {
705 if (s.result_error_bundle.errorMessageCount() > 0) {
706 try ttyconf.setColor(stderr, .red);
707 try stderr.writer().print(" {d} errors\n", .{
708 s.result_error_bundle.errorMessageCount(),
709 });
710 try ttyconf.setColor(stderr, .reset);
711 } else if (!s.test_results.isSuccess()) {
712 try stderr.writer().print(" {d}/{d} passed", .{
713 s.test_results.passCount(), s.test_results.test_count,
714 });
715 if (s.test_results.fail_count > 0) {
716 try stderr.writeAll(", ");
717 try ttyconf.setColor(stderr, .red);
718 try stderr.writer().print("{d} failed", .{
719 s.test_results.fail_count,
720 });
721 try ttyconf.setColor(stderr, .reset);
722 }
723 if (s.test_results.skip_count > 0) {
724 try stderr.writeAll(", ");
725 try ttyconf.setColor(stderr, .yellow);
726 try stderr.writer().print("{d} skipped", .{
727 s.test_results.skip_count,
728 });
729 try ttyconf.setColor(stderr, .reset);
730 }
731 if (s.test_results.leak_count > 0) {
732 try stderr.writeAll(", ");
733 try ttyconf.setColor(stderr, .red);
734 try stderr.writer().print("{d} leaked", .{
735 s.test_results.leak_count,
736 });
737 try ttyconf.setColor(stderr, .reset);
738 }
739 try stderr.writeAll("\n");
740 } else {
741 try ttyconf.setColor(stderr, .red);
742 try stderr.writeAll(" failure\n");
743 try ttyconf.setColor(stderr, .reset);
744 }
745 },
746 }
747766
748 const last_index = if (!failures_only) s.dependencies.items.len -| 1 else blk: {767 const last_index = if (!failures_only) s.dependencies.items.len -| 1 else blk: {
749 var i: usize = s.dependencies.items.len;768 var i: usize = s.dependencies.items.len;
...@@ -897,22 +916,7 @@ fn workerMakeOneStep(...@@ -897,22 +916,7 @@ fn workerMakeOneStep(
897 sub_prog_node.context.lock_stderr();916 sub_prog_node.context.lock_stderr();
898 defer sub_prog_node.context.unlock_stderr();917 defer sub_prog_node.context.unlock_stderr();
899918
900 const stderr = run.stderr;919 printErrorMessages(b, s, run) catch {};
901 const ttyconf = run.ttyconf;
902
903 for (s.result_error_msgs.items) |msg| {
904 // Sometimes it feels like you just can't catch a break. Finally,
905 // with Zig, you can.
906 ttyconf.setColor(stderr, .bold) catch break;
907 stderr.writeAll(s.owner.dep_prefix) catch break;
908 stderr.writeAll(s.name) catch break;
909 stderr.writeAll(": ") catch break;
910 ttyconf.setColor(stderr, .red) catch break;
911 stderr.writeAll("error: ") catch break;
912 ttyconf.setColor(stderr, .reset) catch break;
913 stderr.writeAll(msg) catch break;
914 stderr.writeAll("\n") catch break;
915 }
916 }920 }
917921
918 handle_result: {922 handle_result: {
...@@ -967,6 +971,50 @@ fn workerMakeOneStep(...@@ -967,6 +971,50 @@ fn workerMakeOneStep(
967 }971 }
968}972}
969973
974fn printErrorMessages(b: *std.Build, failing_step: *Step, run: *const Run) !void {
975 const gpa = b.allocator;
976 const stderr = run.stderr;
977 const ttyconf = run.ttyconf;
978
979 // Provide context for where these error messages are coming from by
980 // printing the corresponding Step subtree.
981
982 var step_stack: std.ArrayListUnmanaged(*Step) = .{};
983 defer step_stack.deinit(gpa);
984 try step_stack.append(gpa, failing_step);
985 while (step_stack.items[step_stack.items.len - 1].dependants.items.len != 0) {
986 try step_stack.append(gpa, step_stack.items[step_stack.items.len - 1].dependants.items[0]);
987 }
988
989 // Now, `step_stack` has the subtree that we want to print, in reverse order.
990 try ttyconf.setColor(stderr, .dim);
991 var indent: usize = 0;
992 while (step_stack.popOrNull()) |s| : (indent += 1) {
993 if (indent > 0) {
994 try stderr.writer().writeByteNTimes(' ', (indent - 1) * 3);
995 try printChildNodePrefix(stderr, ttyconf);
996 }
997
998 try stderr.writeAll(s.name);
999
1000 if (s == failing_step) {
1001 try printStepFailure(s, stderr, ttyconf);
1002 } else {
1003 try stderr.writeAll("\n");
1004 }
1005 }
1006 try ttyconf.setColor(stderr, .reset);
1007
1008 // Finally, the actual error messages.
1009 for (failing_step.result_error_msgs.items) |msg| {
1010 try ttyconf.setColor(stderr, .red);
1011 try stderr.writeAll("error: ");
1012 try ttyconf.setColor(stderr, .reset);
1013 try stderr.writeAll(msg);
1014 try stderr.writeAll("\n");
1015 }
1016}
1017
970fn steps(builder: *std.Build, already_ran_build: bool, out_stream: anytype) !void {1018fn steps(builder: *std.Build, already_ran_build: bool, out_stream: anytype) !void {
971 // run the build script to collect the options1019 // run the build script to collect the options
972 if (!already_ran_build) {1020 if (!already_ran_build) {
...@@ -1116,7 +1164,7 @@ fn cleanExit() void {...@@ -1116,7 +1164,7 @@ fn cleanExit() void {
1116const Color = enum { auto, off, on };1164const Color = enum { auto, off, on };
1117const Summary = enum { all, failures, none };1165const Summary = enum { all, failures, none };
11181166
1119fn get_tty_conf(color: Color, stderr: std.fs.File) std.io.tty.Config {1167fn get_tty_conf(color: Color, stderr: File) std.io.tty.Config {
1120 return switch (color) {1168 return switch (color) {
1121 .auto => std.io.tty.detectConfig(stderr),1169 .auto => std.io.tty.detectConfig(stderr),
1122 .on => .escape_codes,1170 .on => .escape_codes,