Commit cd3d8f3a4ee22a41098b1daf2a36d7fbb342d0fa | zig

author	Wooster <r00ster91@proton.me> 2022-10-13 12:39:24+02:00
committer	GitHub <noreply@github.com> 2022-10-13 06:39:24-04:00
log	cd3d8f3a4ee22a41098b1daf2a36d7fbb342d0fa
tree	30a12bba3b498df3dad71c1379ec93421ab5ea3a
parent	0b47e69b7c0aedbc142400305cda86ef58b41656
signature	Signed by PGP key 4AEE18F83AFDEB23

`std.Progress`: fix inaccurate line truncation and use optimal max terminal width (#12079)

* prep: output_buffer -> output_buffer_slice

* fix: truncate lines accurately

Currently, the code assumes a terminal width of 100.

If we look at what's printed for the last test:
```
Test [1/1] test "basic functionality"... [101/100] this is a really long name designed to activate the truncation code. let's fi...
```
No, it does not really work because the relevant part here is `"[101/100] this is a really long name designed to activate the truncation code. let's fi... "`,
which is 90 characters, but we expect 100 because that's the width that is assumed.
The reason is that it also measures **unprintable characters** (escape sequences) at least non-Windows systems.
With this commit the output is now:
```
Test [1/1] test "basic functionality"... [101/100] this is a really long name designed to activate the truncation code. let's find out if...
```
Of which `"[101/100] this is a really long name designed to activate the truncation code. let's find out if... "`
is the actual output of *our* `std.Progress` (remember that `zig test` has an `std.Progress` and our test itself does).
The length of that string is 100. Now the length is consistent with Windows where we don't use escape sequences. This issue was only present on non-Windows systems.

* feat: decide optimal maximum width

This is done by 1. getting the current terminal width and 2. subtracting that by the current cursor column. This accounts for previous output from someone else.

* test: add more tests

They make it easier to see how the progress line is printed in different cases.

* style: fix typo and improve docs

It also expands an acronym used as a variable name. It confused me.

* cleanup: import std.time

* test: add test

* fix: limit termios usage to Linux only for now

* fix: missing cast on Windows

* test: try to debug failure

* fix: fix off-by-one and disable tests

* docs: make comment clearer

* fix: more durability

* fix(getTerminalWidth): change order

1 files changed, 219 insertions(+), 44 deletions(-)

lib
- std
  - Progress.zig

lib/std/Progress.zig+219-44

...	...	@@ -1,23 +1,30 @@
1		//! This API non-allocating, non-fallible, and thread-safe.
	1	//! This is a non-allocating, non-fallible, and thread-safe API for printing
	2	//! progress indicators to the terminal.
2	3	//! The tradeoff is that users of this API must provide the storage
3	4	//! for each `Progress.Node`.
4	5	//!
	6	//! This library purposefully keeps its output simple and is ASCII-compatible.
	7	//!
5	8	//! Initialize the struct directly, overriding these fields as desired:
6	9	//! * `refresh_rate_ms`
7	10	//! * `initial_delay_ms`
	11	//! * `dont_print_on_dumb`
	12	//! * `max_width`
8	13
9	14	const std = @import("std");
10	15	const builtin = @import("builtin");
11	16	const windows = std.os.windows;
12	17	const testing = std.testing;
13	18	const assert = std.debug.assert;
	19	const os = std.os;
	20	const time = std.time;
14	21	const Progress = @This();
15	22
16	23	/// `null` if the current node (and its children) should
17	24	/// not print on update()
18	25	terminal: ?std.fs.File = undefined,
19	26
20		/// Is this a windows API terminal (note: this is not the same as being run on windows
	27	/// Is this a Windows API terminal (note: this is not the same as being run on Windows
21	28	/// because other terminals exist like MSYS/git-bash)
22	29	is_windows_terminal: bool = false,
23	30
...	...	@@ -35,7 +42,7 @@ root: Node = undefined,
35	42
36	43	/// Keeps track of how much time has passed since the beginning.
37	44	/// Used to compare with `initial_delay_ms` and `refresh_rate_ms`.
38		timer: ?std.time.Timer = null,
	45	timer: ?time.Timer = null,
39	46
40	47	/// When the previous refresh was written to the terminal.
41	48	/// Used to compare with `refresh_rate_ms`.
...	...	@@ -43,13 +50,20 @@ prev_refresh_timestamp: u64 = undefined,
43	50
44	51	/// This buffer represents the maximum number of bytes written to the terminal
45	52	/// with each refresh.
46		output_buffer: [100]u8 = undefined,
	53	output_buffer: [256]u8 = undefined,
	54	output_buffer_slice: []u8 = undefined,
	55
	56	/// This is the maximum number of bytes written to the terminal with each refresh.
	57	///
	58	/// It is recommended to leave this as `null` so that `start` can automatically decide an
	59	/// optimal width for the terminal.
	60	max_width: ?usize = null,
47	61
48	62	/// How many nanoseconds between writing updates to the terminal.
49		refresh_rate_ns: u64 = 50 * std.time.ns_per_ms,
	63	refresh_rate_ns: u64 = 50 * time.ns_per_ms,
50	64
51		/// How many nanoseconds to keep the output hidden
52		initial_delay_ns: u64 = 500 * std.time.ns_per_ms,
	65	/// How many nanoseconds to keep the output hidden.
	66	initial_delay_ns: u64 = 500 * time.ns_per_ms,
53	67
54	68	done: bool = true,
55	69
...	...	@@ -62,11 +76,14 @@ update_mutex: std.Thread.Mutex = .{},
62	76	/// we can move the cursor back later.
63	77	columns_written: usize = undefined,
64	78
	79	const truncation_suffix = "... ";
	80
65	81	/// Represents one unit of progress. Each node can have children nodes, or
66	82	/// one can use integers with `update`.
67	83	pub const Node = struct {
68	84	context: *Progress,
69	85	parent: ?*Node,
	86	/// The name that will be displayed for this node.
70	87	name: []const u8,
71	88	/// Must be handled atomically to be thread-safe.
72	89	recently_updated_child: ?*Node = null,
...	...	@@ -155,6 +172,22 @@ pub fn start(self: Progress, name: []const u8, estimated_total_items: usize) N
155	172	// we are in a "dumb" terminal like in acme or writing to a file
156	173	self.terminal = stderr;
157	174	}
	175	if (self.max_width == null) {
	176	if (self.terminal) \|terminal\| {
	177	// choose an optimal width and account for progress output that could have been printed
	178	// before us by another `std.Progress` instance
	179	const terminal_width = self.getTerminalWidth(terminal.handle) catch 100;
	180	const chars_already_printed = self.getTerminalCursorColumn(terminal) catch 0;
	181	self.max_width = terminal_width - chars_already_printed;
	182	} else {
	183	self.max_width = 100;
	184	}
	185	}
	186	self.max_width = std.math.clamp(
	187	self.max_width.?,
	188	truncation_suffix.len, // make sure we can at least truncate
	189	self.output_buffer.len - 1,
	190	);
158	191	self.root = Node{
159	192	.context = self,
160	193	.parent = null,
...	...	@@ -164,11 +197,64 @@ pub fn start(self: Progress, name: []const u8, estimated_total_items: usize) N
164	197	};
165	198	self.columns_written = 0;
166	199	self.prev_refresh_timestamp = 0;
167		self.timer = std.time.Timer.start() catch null;
	200	self.timer = time.Timer.start() catch null;
168	201	self.done = false;
169	202	return &self.root;
170	203	}
171	204
	205	fn getTerminalWidth(self: Progress, file_handle: os.fd_t) !u16 {
	206	if (builtin.os.tag == .linux) {
	207	// TODO: figure out how to get this working on FreeBSD, macOS etc. too.
	208	// they too should have capabilities to figure out the cursor column.
	209	var winsize: os.linux.winsize = undefined;
	210	switch (os.errno(os.linux.ioctl(file_handle, os.linux.T.IOCGWINSZ, @ptrToInt(&winsize)))) {
	211	.SUCCESS => return winsize.ws_col,
	212	else => return error.Unexpected,
	213	}
	214	} else if (builtin.os.tag == .windows) {
	215	std.debug.assert(self.is_windows_terminal);
	216	var info: windows.CONSOLE_SCREEN_BUFFER_INFO = undefined;
	217	if (windows.kernel32.GetConsoleScreenBufferInfo(file_handle, &info) != windows.TRUE)
	218	return error.Unexpected;
	219	return @intCast(u16, info.dwSize.X);
	220	} else {
	221	return error.Unsupported;
	222	}
	223	}
	224
	225	fn getTerminalCursorColumn(self: Progress, file: std.fs.File) !u16 {
	226	// TODO: figure out how to get this working on FreeBSD, macOS etc. too.
	227	// they too should have termios or capabilities to figure out the terminal width.
	228	if (builtin.os.tag == .linux and self.supports_ansi_escape_codes) {
	229	// First, disable echo and enable non-canonical mode
	230	// (so that no enter press required for us to read the output of the escape sequence below)
	231	const original_termios = try os.tcgetattr(file.handle);
	232	var new_termios = original_termios;
	233	new_termios.lflag &= ~(os.linux.ECHO \| os.linux.ICANON);
	234	try os.tcsetattr(file.handle, .NOW, new_termios);
	235	defer os.tcsetattr(file.handle, .NOW, original_termios) catch {
	236	// Sorry for ruining your terminal
	237	};
	238
	239	try file.writeAll("\x1b[6n");
	240	var buf: ["\x1b[256;256R".len]u8 = undefined;
	241	const output = try file.reader().readUntilDelimiter(&buf, 'R');
	242	var splitter = std.mem.split(u8, output, ";");
	243	_ = splitter.next().?; // skip first half
	244	const column_half = splitter.next() orelse return error.UnexpectedEnd;
	245	const column = try std.fmt.parseUnsigned(u16, column_half, 10);
	246	return column - 1; // it's one-based
	247	} else if (builtin.os.tag == .windows) {
	248	std.debug.assert(self.is_windows_terminal);
	249	var info: windows.CONSOLE_SCREEN_BUFFER_INFO = undefined;
	250	if (windows.kernel32.GetConsoleScreenBufferInfo(file.handle, &info) != windows.TRUE)
	251	return error.Unexpected;
	252	return @intCast(u16, info.dwCursorPosition.X);
	253	} else {
	254	return error.Unsupported;
	255	}
	256	}
	257
172	258	/// Updates the terminal if enough time has passed since last update. Thread-safe.
173	259	pub fn maybeRefresh(self: *Progress) void {
174	260	if (self.timer) \|*timer\| {
...	...	@@ -198,14 +284,16 @@ fn refreshWithHeldLock(self: *Progress) void {
198	284
199	285	const file = self.terminal orelse return;
200	286
	287	// prepare for printing unprintable characters
	288	self.output_buffer_slice = &self.output_buffer;
	289
201	290	var end: usize = 0;
202	291	if (self.columns_written > 0) {
203	292	// restore the cursor position by moving the cursor
204		// `columns_written` cells to the left, then clear the rest of the
205		// line
	293	// `columns_written` cells to the left, then clear the rest of the line
206	294	if (self.supports_ansi_escape_codes) {
207		end += (std.fmt.bufPrint(self.output_buffer[end..], "\x1b[{d}D", .{self.columns_written}) catch unreachable).len;
208		end += (std.fmt.bufPrint(self.output_buffer[end..], "\x1b[0K", .{}) catch unreachable).len;
	295	end += (std.fmt.bufPrint(self.output_buffer_slice[end..], "\x1b[{d}D", .{self.columns_written}) catch unreachable).len;
	296	end += (std.fmt.bufPrint(self.output_buffer_slice[end..], "\x1b[0K", .{}) catch unreachable).len;
209	297	} else if (builtin.os.tag == .windows) winapi: {
210	298	std.debug.assert(self.is_windows_terminal);
211	299
...	...	@@ -247,47 +335,53 @@ fn refreshWithHeldLock(self: *Progress) void {
247	335	unreachable;
248	336	} else {
249	337	// we are in a "dumb" terminal like in acme or writing to a file
250		self.output_buffer[end] = '\n';
	338	self.output_buffer_slice[end] = '\n';
251	339	end += 1;
252	340	}
253	341
254	342	self.columns_written = 0;
255	343	}
256	344
	345	// from here on we will write printable characters. we also make sure the unprintable characters
	346	// we possibly wrote previously don't affect whether we truncate the line in `bufWrite`.
	347	const unprintables = end;
	348	end = 0;
	349	self.output_buffer_slice = self.output_buffer[unprintables .. unprintables + self.max_width.?];
	350
257	351	if (!self.done) {
258		var need_ellipse = false;
	352	var need_ellipsis = false;
259	353	var maybe_node: ?*Node = &self.root;
260	354	while (maybe_node) \|node\| {
261		if (need_ellipse) {
	355	if (need_ellipsis) {
262	356	self.bufWrite(&end, "... ", .{});
263	357	}
264		need_ellipse = false;
265		const eti = @atomicLoad(usize, &node.unprotected_estimated_total_items, .Monotonic);
	358	need_ellipsis = false;
	359	const estimated_total_items = @atomicLoad(usize, &node.unprotected_estimated_total_items, .Monotonic);
266	360	const completed_items = @atomicLoad(usize, &node.unprotected_completed_items, .Monotonic);
267	361	const current_item = completed_items + 1;
268		if (node.name.len != 0 or eti > 0) {
	362	if (node.name.len != 0 or estimated_total_items > 0) {
269	363	if (node.name.len != 0) {
270	364	self.bufWrite(&end, "{s}", .{node.name});
271		need_ellipse = true;
	365	need_ellipsis = true;
272	366	}
273		if (eti > 0) {
274		if (need_ellipse) self.bufWrite(&end, " ", .{});
275		self.bufWrite(&end, "[{d}/{d}] ", .{ current_item, eti });
276		need_ellipse = false;
	367	if (estimated_total_items > 0) {
	368	if (need_ellipsis) self.bufWrite(&end, " ", .{});
	369	self.bufWrite(&end, "[{d}/{d}] ", .{ current_item, estimated_total_items });
	370	need_ellipsis = false;
277	371	} else if (completed_items != 0) {
278		if (need_ellipse) self.bufWrite(&end, " ", .{});
	372	if (need_ellipsis) self.bufWrite(&end, " ", .{});
279	373	self.bufWrite(&end, "[{d}] ", .{current_item});
280		need_ellipse = false;
	374	need_ellipsis = false;
281	375	}
282	376	}
283	377	maybe_node = @atomicLoad(?*Node, &node.recently_updated_child, .Acquire);
284	378	}
285		if (need_ellipse) {
	379	if (need_ellipsis) {
286	380	self.bufWrite(&end, "... ", .{});
287	381	}
288	382	}
289	383
290		_ = file.write(self.output_buffer[0..end]) catch {
	384	_ = file.write(self.output_buffer[0 .. end + unprintables]) catch {
291	385	// Stop trying to write to this file once it errors.
292	386	self.terminal = null;
293	387	};
...	...	@@ -310,32 +404,113 @@ pub fn log(self: *Progress, comptime format: []const u8, args: anytype) void {
310	404	}
311	405
312	406	fn bufWrite(self: Progress, end: usize, comptime format: []const u8, args: anytype) void {
313		if (std.fmt.bufPrint(self.output_buffer[end.*..], format, args)) \|written\| {
	407	if (std.fmt.bufPrint(self.output_buffer_slice[end.*..], format, args)) \|written\| {
314	408	const amt = written.len;
315	409	end.* += amt;
316	410	self.columns_written += amt;
317	411	} else \|err\| switch (err) {
318	412	error.NoSpaceLeft => {
319		self.columns_written += self.output_buffer.len - end.*;
320		end.* = self.output_buffer.len;
321		const suffix = "... ";
322		std.mem.copy(u8, self.output_buffer[self.output_buffer.len - suffix.len ..], suffix);
	413	// truncate the line with a suffix.
	414	// for example if we have "hello world" (len=11) and 10 is the limit,
	415	// it would become "hello w... "
	416	self.columns_written += self.output_buffer_slice.len - end.*;
	417	end.* = self.output_buffer_slice.len;
	418	std.mem.copy(
	419	u8,
	420	self.output_buffer_slice[self.output_buffer_slice.len - truncation_suffix.len ..],
	421	truncation_suffix,
	422	);
323	423	},
324	424	}
325	425	}
326	426
327		test "basic functionality" {
328		var disable = true;
329		if (disable) {
330		// This test is disabled because it uses time.sleep() and is therefore slow. It also
331		// prints bogus progress data to stderr.
	427	// By default these tests are disabled because they use time.sleep()
	428	// and are therefore slow. They also prints bogus progress data to stderr.
	429	const skip_tests = true;
	430
	431	test "behavior on buffer overflow" {
	432	if (skip_tests)
	433	return error.SkipZigTest;
	434
	435	// move the cursor
	436	std.debug.print("{s}", .{"A" ** 300});
	437
	438	var progress = Progress{};
	439
	440	const long_string = "A" ** 300;
	441	var node = progress.start(long_string, 0);
	442
	443	const speed_factor = time.ns_per_s / 4;
	444
	445	time.sleep(speed_factor);
	446	node.activate();
	447	time.sleep(speed_factor);
	448	node.end();
	449	}
	450
	451	test "multiple tasks with long names" {
	452	if (skip_tests)
332	453	return error.SkipZigTest;
	454
	455	var progress = Progress{};
	456
	457	const tasks = [_][]const u8{
	458	"A" ** 99,
	459	"A" ** 100,
	460	"A" ** 101,
	461	"A" ** 102,
	462	"A" ** 103,
	463	};
	464
	465	const speed_factor = time.ns_per_s / 6;
	466
	467	for (tasks) \|task\| {
	468	var node = progress.start(task, 3);
	469	time.sleep(speed_factor);
	470	node.activate();
	471
	472	time.sleep(speed_factor);
	473	node.completeOne();
	474	time.sleep(speed_factor);
	475	node.completeOne();
	476	time.sleep(speed_factor);
	477	node.completeOne();
	478
	479	node.end();
333	480	}
	481	}
	482
	483	test "very short max width" {
	484	if (skip_tests)
	485	return error.SkipZigTest;
	486
	487	var progress = Progress{ .max_width = 4 };
	488
	489	const task = "A" ** 300;
	490
	491	const speed_factor = time.ns_per_s / 2;
	492
	493	var node = progress.start(task, 3);
	494	time.sleep(speed_factor);
	495	node.activate();
	496
	497	time.sleep(speed_factor);
	498	node.completeOne();
	499	time.sleep(speed_factor);
	500	node.completeOne();
	501
	502	node.end();
	503	}
	504
	505	test "basic functionality" {
	506	if (skip_tests)
	507	return error.SkipZigTest;
	508
334	509	var progress = Progress{};
335	510	const root_node = progress.start("", 100);
336	511	defer root_node.end();
337	512
338		const speed_factor = std.time.ns_per_ms;
	513	const speed_factor = time.ns_per_ms;
339	514
340	515	const sub_task_names = [_][]const u8{
341	516	"reticulating splines",
...	...	@@ -352,24 +527,24 @@ test "basic functionality" {
352	527	next_sub_task = (next_sub_task + 1) % sub_task_names.len;
353	528
354	529	node.completeOne();
355		std.time.sleep(5 * speed_factor);
	530	time.sleep(5 * speed_factor);
356	531	node.completeOne();
357	532	node.completeOne();
358		std.time.sleep(5 * speed_factor);
	533	time.sleep(5 * speed_factor);
359	534	node.completeOne();
360	535	node.completeOne();
361		std.time.sleep(5 * speed_factor);
	536	time.sleep(5 * speed_factor);
362	537
363	538	node.end();
364	539
365		std.time.sleep(5 * speed_factor);
	540	time.sleep(5 * speed_factor);
366	541	}
367	542	{
368	543	var node = root_node.start("this is a really long name designed to activate the truncation code. let's find out if it works", 0);
369	544	node.activate();
370		std.time.sleep(10 * speed_factor);
	545	time.sleep(10 * speed_factor);
371	546	progress.refresh();
372		std.time.sleep(10 * speed_factor);
	547	time.sleep(10 * speed_factor);
373	548	node.end();
374	549	}
375	550	}