mirrors/ghostty
1
0
Fork 0
mirror of https://github.com/ghostty-org/ghostty.git synced 2026-07-10 11:19:45 +00:00
Code Issues Packages Projects Releases Wiki Activity

terminal: log unsupported-input messages once per distinct value

Browse Source 
Profiling terminal-stream on a 2.6 GB recording of real terminal
sessions showed ~5% of total time under writev, all of it log
output: the recording triggers ~120k warnings, dominated by a few
repeated messages ("unimplemented mode: 34", "invalid device
attributes command", "invalid C0 character") that some program in
the recorded session re-emitted on every frame or every prompt.
Each occurrence pays formatting plus a blocking write syscall,
and repeats add no diagnostic value beyond the first: the message
already includes the offending value.

These messages are emitted in response to input that the terminal
application controls, so a misbehaving or merely chatty program
can flood the log indefinitely. This adds a logUnsupportedOnce
helper that suppresses repeats per (call site, value): each site
tracks the distinct keys it has logged (the mode number, final
byte, or first parameter, depending on the site) in a small fixed
table of 16 u32 slots, 64 bytes per site. Real streams only ever
produce a handful of distinct unsupported values per site, so if a
table fills, new values are suppressed too; by then the log
already shows the problem class and unbounded distinct values
would flood it anyway. Slots are claimed with 32-bit atomics
(native on wasm32) and never change afterwards, so lookups are a
lock-free scan and the worst case race is a duplicate message.

The OSC 1 change-icon message moves from info to warn to match the
other unsupported-input messages the helper covers.

Measured with ghostty-bench terminal-stream (2.6 GB real-session
corpus, 120x80, M4 Max, ReleaseFast, hyperfine means of 5 runs,
stderr to /dev/null which undersells the cost of a real log sink):

| stream                     | before  | after   | change |
|----------------------------|---------|---------|--------|
| real 2.6 GB session corpus | 7.916 s | 7.674 s | +3.2%  |

System time drops from 0.49 s to 0.22 s from the eliminated
writev calls.
This commit is contained in:
Mitchell Hashimoto
2026-07-06 13:14:06 -07:00
parent 8d663a76e9
commit b5053153f4
1 changed files with 85 additions and 10 deletions
Download Patch File Download Diff File Expand all files Collapse all files

95
src/terminal/stream.zig
View File

@@ -1011,7 +1011,7 @@ pub fn Stream(comptime H: type) type {
.SO => self.handler.vt(.invoke_charset, .{ .bank = .GL, .charset = .G1, .locking = false }),
.SI => self.handler.vt(.invoke_charset, .{ .bank = .GL, .charset = .G0, .locking = false }),
else => log.warn("invalid C0 character, ignoring: 0x{x}", .{c}),
else => logUnsupportedOnce("invalid C0 character, ignoring: 0x{x}", .{c}, c),
}
}
@@ -1529,7 +1529,11 @@ pub fn Stream(comptime H: type) type {
if (req) |r| {
self.handler.vt(.device_attributes, r);
} else {
log.warn("invalid device attributes command: {f}", .{input});
logUnsupportedOnce(
"invalid device attributes command: {f}",
.{input},
if (input.params.len > 0) input.params[0] else 0,
);
return;
}
},
@@ -1615,7 +1619,7 @@ pub fn Stream(comptime H: type) type {
if (modes.modeFromInt(mode_int, ansi_mode)) |mode| {
self.handler.vt(.set_mode, .{ .mode = mode });
} else {
log.warn("unimplemented mode: {}", .{mode_int});
logUnsupportedOnce("unimplemented mode: {}", .{mode_int}, mode_int);
}
}
},
@@ -1636,7 +1640,7 @@ pub fn Stream(comptime H: type) type {
if (modes.modeFromInt(mode_int, ansi_mode)) |mode| {
self.handler.vt(.reset_mode, .{ .mode = mode });
} else {
log.warn("unimplemented mode: {}", .{mode_int});
logUnsupportedOnce("unimplemented mode: {}", .{mode_int}, mode_int);
}
}
},
@@ -1705,9 +1709,10 @@ pub fn Stream(comptime H: type) type {
self.handler.vt(.modify_key_format, format);
},
else => log.warn(
else => logUnsupportedOnce(
"unknown CSI m with intermediate: {}",
.{input.intermediates[0]},
input.intermediates[0],
),
},
@@ -2039,13 +2044,15 @@ pub fn Stream(comptime H: type) type {
23 => self.handler.vt(.title_pop, index),
else => @compileError("unreachable"),
}
} else log.warn(
} else logUnsupportedOnce(
"ignoring CSI 22/23 t with extra parameters: {f}",
.{input},
input.params[0],
),
else => log.warn(
else => logUnsupportedOnce(
"ignoring CSI t with unimplemented parameter: {f}",
.{input},
input.params[0],
),
}
} else log.err(
@@ -2220,7 +2227,11 @@ pub fn Stream(comptime H: type) type {
.change_window_icon => |icon| {
@branchHint(.likely);
log.info("OSC 1 (change icon) received and ignored icon={s}", .{icon});
logUnsupportedOnce(
"OSC 1 (change icon) received and ignored icon={s}",
.{icon},
0,
);
},
.clipboard_contents => |clip| {
@@ -2412,7 +2423,11 @@ pub fn Stream(comptime H: type) type {
else => {}, // fall through
}
log.warn("unimplemented ESC action: {f}", .{action});
logUnsupportedOnce(
"unimplemented ESC action: {f}",
.{action},
action.final,
);
},
// IND - Index
@@ -2606,12 +2621,72 @@ pub fn Stream(comptime H: type) type {
@branchHint(.likely);
},
else => log.warn("unimplemented ESC action: {f}", .{action}),
else => logUnsupportedOnce(
"unimplemented ESC action: {f}",
.{action},
action.final,
),
}
}
};
}
/// Logs an unsupported-input message at most once per distinct key
/// per process.
///
/// These messages are emitted in response to input that the terminal
/// application controls, so a misbehaving (or merely chatty) program
/// can trigger the same message millions of times, e.g. by toggling
/// an unimplemented mode on every frame. Each log call has a real
/// throughput cost (formatting plus a blocking write per message)
/// while adding no diagnostic value beyond the first occurrence.
///
/// The keys seen so far are tracked in a small fixed table (64 bytes)
/// instantiated per (format, argument type) tuple, i.e. roughly per
/// call site. Real streams only ever produce a handful of distinct
/// unsupported values per site, so if the table ever fills, messages
/// for further new values are suppressed as well: by that point the
/// log already shows this class of problem and unbounded distinct
/// values would flood it anyway.
fn logUnsupportedOnce(
comptime format: []const u8,
args: anytype,
key: u16,
) void {
// u32 slots so every u16 key is representable alongside an empty
// sentinel and so 32-bit targets (e.g. wasm32) have native
// atomics.
const empty = std.math.maxInt(u32);
const Static = struct {
var seen: [16]u32 = @splat(empty);
};
// The atomics make concurrent streams safe: slots are only ever
// claimed, never changed, so the scan can stop at the first empty
// slot. The worst case race is a benign duplicate message.
for (&Static.seen) |*slot| {
const cur = @atomicLoad(u32, slot, .acquire);
if (cur == key) return; // already logged
if (cur != empty) continue; // other key, keep scanning
// Empty slot: claim it for this key and log below.
const actual = @cmpxchgStrong(
u32,
slot,
empty,
key,
.acq_rel,
.acquire,
) orelse break;
// Lost the race: suppress if it was to the same key, keep
// scanning otherwise.
if (actual == key) return;
} else return; // table full: suppress new values too
log.warn(format, args);
}
test Action {
// Forces the C type to be reified when the target is C, ensuring
// all our types are C ABI compatible.