Show only the last few log lines while building (#40386)
John Stephens committed
May 4, 2026 at 20:07 UTC
c744ac58940cb50f719eac060efce986ea715433
7 files changed
+347
-49
src/windows/wslc/services/BuildImageCallback.cpp
+199
-2
@@ -16,14 +16,211 @@ Abstract:
16
#include "BuildImageCallback.h"
17
18
namespace wsl::windows::wslc::services {
19
-HRESULT BuildImageCallback::OnProgress(LPCSTR status, LPCSTR /*id*/, ULONGLONG /*current*/, ULONGLONG /*total*/)
19
+
20
+using wsl::windows::common::string::MultiByteToWide;
21
+
22
+BuildImageCallback::~BuildImageCallback()
23
+try
24
+{
25
+ // Capture any partial line so it's included in the error replay below; otherwise
26
+ // CollapseWindow() would discard it.
27
+ if (!m_pendingLine.empty())
28
+ {
29
+ m_pendingLine += '\n';
30
+ m_allLines.push_back(std::move(m_pendingLine));
31
+ }
32
+
33
+ CollapseWindow();
34
+
35
+ // On build error (not cancellation), replay the full log output so the user can see what went wrong.
36
+ if (!IsCancelled() && std::uncaught_exceptions() > m_uncaughtExceptions && !m_allLines.empty())
37
+ {
38
+ for (const auto& line : m_allLines)
39
+ {
40
+ WriteTerminal(MultiByteToWide(line));
41
+ }
42
+ }
43
+}
44
+CATCH_LOG()
45
+
46
+void BuildImageCallback::WriteTerminal(std::wstring_view content) const
47
+{
48
+ DWORD written;
49
+ LOG_IF_WIN32_BOOL_FALSE(WriteConsoleW(m_console, content.data(), static_cast<DWORD>(content.size()), &written, nullptr));
50
+}
51
+
52
+bool BuildImageCallback::IsCancelled() const
53
+{
54
+ return WaitForSingleObject(m_cancelEvent, 0) == WAIT_OBJECT_0;
55
+}
56
+
57
+void BuildImageCallback::CollapseWindow()
58
+{
59
+ if (m_displayedLines > 0)
60
+ {
61
+ WriteTerminal(std::format(L"\033[{}A\033[J", m_displayedLines));
62
+ m_displayedLines = 0;
63
+ }
64
+
65
+ m_lines.clear();
66
+ m_pendingLine.clear();
67
+}
68
+
69
+HRESULT BuildImageCallback::OnProgress(LPCSTR status, LPCSTR id, ULONGLONG /*current*/, ULONGLONG /*total*/)
70
try
71
{
22
- if (status != nullptr && *status != '\0')
72
+ if (status == nullptr || *status == '\0')
73
+ {
74
+ return S_OK;
75
+ }
76
+
77
+ // When cancellation is pending, skip all processing so the server's IO loop can
78
+ // return to its event wait and detect the cancel event promptly.
79
+ if (IsCancelled())
80
+ {
81
+ return S_OK;
82
+ }
83
+
84
+ if (m_verbose || !m_isConsole)
85
{
86
wprintf(L"%hs", status);
87
+ return S_OK;
88
+ }
89
+
90
+ // Match the specific "log" sentinel sent by WSLCSession::BuildImage rather than
91
+ // accepting any non-empty id, so future or unrelated id usage defaults to permanent.
92
+ const bool isLog = (id != nullptr && std::string_view{id} == "log");
93
+
94
+ if (!isLog)
95
+ {
96
+ // Permanent line: collapse the scrolling window then print directly.
97
+ CollapseWindow();
98
+ WriteTerminal(MultiByteToWide(status));
99
+ return S_OK;
100
+ }
101
+
102
+ // Log line: add to the scrolling window.
103
+ for (const char* p = status; *p != '\0'; ++p)
104
+ {
105
+ if (*p == '\n')
106
+ {
107
+ // Store with the trailing newline so the byte count matches what is replayed.
108
+ // Cap retained log output to avoid unbounded growth on very long builds.
109
+ m_allLines.push_back(m_pendingLine + '\n');
110
+ m_allLinesBytes += m_allLines.back().size();
111
+ while (m_allLinesBytes > c_maxAllLinesBytes && !m_allLines.empty())
112
+ {
113
+ m_allLinesBytes -= m_allLines.front().size();
114
+ m_allLines.pop_front();
115
+ }
116
+
117
+ m_lines.push_back(std::move(m_pendingLine));
118
+ m_pendingLine.clear();
119
+ if (m_lines.size() > c_maxDisplayLines)
120
+ {
121
+ m_lines.pop_front();
122
+ }
123
+ }
124
+ else if (*p == '\r')
125
+ {
126
+ // \r\n is a line ending; standalone \r overwrites the current line.
127
+ if (*(p + 1) != '\n')
128
+ {
129
+ // Flush a throttled redraw before clearing so \r-based progress
130
+ // updates are visible even when batched in a single OnProgress call.
131
+ auto now = std::chrono::steady_clock::now();
132
+ if (!m_pendingLine.empty() && now - m_lastRedraw >= c_redrawInterval)
133
+ {
134
+ Redraw();
135
+ m_lastRedraw = now;
136
+ }
137
+ m_pendingLine.clear();
138
+ }
139
+ }
140
+ else
141
+ {
142
+ m_pendingLine += *p;
143
+ }
144
+ }
145
+
146
+ // Throttle redraws to avoid blocking the server's IO loop with console writes
147
+ // during rapid output. Lines accumulate in the deque immediately; the display
148
+ // catches up at ~20fps.
149
+ auto now = std::chrono::steady_clock::now();
150
+ if (now - m_lastRedraw >= c_redrawInterval)
151
+ {
152
+ Redraw();
153
+ m_lastRedraw = now;
154
}
155
+
156
return S_OK;
157
}
158
CATCH_RETURN();
159
+
160
+void BuildImageCallback::Redraw()
161
+{
162
+ CONSOLE_SCREEN_BUFFER_INFO info{};
163
+ THROW_IF_WIN32_BOOL_FALSE(GetConsoleScreenBufferInfo(m_console, &info));
164
+ // Use the visible window width (not buffer width), minus one column to avoid the
165
+ // deferred-wrap edge case when a line is exactly the window width. Clamp to at
166
+ // least zero so the value never goes negative (which would underflow when passed
167
+ // to std::wstring::resize).
168
+ const SHORT consoleWidth = std::max<SHORT>(0, info.srWindow.Right - info.srWindow.Left);
169
+
170
+ // Determine how many completed lines to show, leaving room for the pending line.
171
+ const bool showPending = !m_pendingLine.empty();
172
+ SHORT completedCount = static_cast<SHORT>(m_lines.size());
173
+ if (showPending && completedCount >= c_maxDisplayLines)
174
+ {
175
+ completedCount = c_maxDisplayLines - 1;
176
+ }
177
+ const SHORT displayCount = completedCount + (showPending ? 1 : 0);
178
+
179
+ // Build the entire frame in one buffer to minimize console writes. Hide the cursor
180
+ // during the redraw so the user doesn't see it bouncing through the cursor movement,
181
+ // then show it again at the final position. The dim attribute (\033[2m) renders the
182
+ // scrolling lines de-emphasized regardless of the user's theme.
183
+ std::wstring buffer = L"\033[?25l\033[2m";
184
+
185
+ // Move cursor to the start of the display area and erase from there to the end of
186
+ // the screen. \033[J handles the case where the new display is shorter than the
187
+ // previous one (e.g. when \r clears the pending line without a replacement).
188
+ if (m_displayedLines > 0)
189
+ {
190
+ buffer += std::format(L"\033[{}A\033[J", m_displayedLines);
191
+ }
192
+
193
+ auto appendLine = [&](const std::string& line) {
194
+ auto wline = MultiByteToWide(line);
195
+ if (static_cast<SHORT>(wline.size()) > consoleWidth)
196
+ {
197
+ wline.resize(consoleWidth);
198
+ }
199
+ buffer += wline;
200
+ buffer += L"\033[K\n";
201
+ };
202
+
203
+ // Print completed lines (skip older ones if we need room for the pending line).
204
+ auto it = m_lines.begin();
205
+ if (completedCount < static_cast<SHORT>(m_lines.size()))
206
+ {
207
+ std::advance(it, m_lines.size() - completedCount);
208
+ }
209
+ for (; it != m_lines.end(); ++it)
210
+ {
211
+ appendLine(*it);
212
+ }
213
+
214
+ // Print the in-progress line (e.g. \r-based progress updates).
215
+ if (showPending)
216
+ {
217
+ appendLine(m_pendingLine);
218
+ }
219
+
220
+ buffer += L"\033[22m\033[?25h";
221
+
222
+ WriteTerminal(buffer);
223
+ m_displayedLines = displayCount;
224
+}
225
+
226
} // namespace wsl::windows::wslc::services
src/windows/wslc/services/BuildImageCallback.h
+36
@@ -12,13 +12,49 @@ Abstract:
12
13
--*/
14
#pragma once
15
+#include "ChangeTerminalMode.h"
16
#include "SessionService.h"
17
+#include <deque>
18
19
namespace wsl::windows::wslc::services {
20
class DECLSPEC_UUID("3EDD5DBF-CA6C-4CF7-923A-AD94B6A732E5") BuildImageCallback
21
: public Microsoft::WRL::RuntimeClass<Microsoft::WRL::RuntimeClassFlags<Microsoft::WRL::ClassicCom>, IProgressCallback, IFastRundown>
22
{
23
public:
24
+ // The cancel event handle must remain valid for the lifetime of this callback.
25
+ BuildImageCallback(HANDLE cancelEvent, bool verbose) : m_verbose(verbose), m_cancelEvent(cancelEvent)
26
+ {
27
+ }
28
+ ~BuildImageCallback();
29
HRESULT OnProgress(LPCSTR status, LPCSTR id, ULONGLONG current, ULONGLONG total) override;
30
+
31
+private:
32
+ static constexpr SHORT c_maxDisplayLines = 16;
33
+ static constexpr auto c_redrawInterval = std::chrono::milliseconds(50);
34
+ static constexpr size_t c_maxAllLinesBytes = 10 * 1024 * 1024; // 10 MiB cap on retained log output for error replay.
35
+
36
+ void CollapseWindow();
37
+ void Redraw();
38
+ // Use WriteConsoleW directly rather than wprintf: wprintf is noticeably slower for
39
+ // the per-redraw scrolling display and produces visible flicker.
40
+ void WriteTerminal(std::wstring_view content) const;
41
+ bool IsCancelled() const;
42
+
43
+ const bool m_verbose;
44
+ const HANDLE m_cancelEvent;
45
+ HANDLE m_console = GetStdHandle(STD_OUTPUT_HANDLE);
46
+ bool m_isConsole = wsl::windows::common::wslutil::IsConsoleHandle(m_console);
47
+ EnableVirtualTerminal m_vtMode{m_console};
48
+ std::deque<std::string> m_lines;
49
+ // Each entry already contains the trailing newline so the bytes match what's replayed.
50
+ // TODO: Track logs per step so the destructor can replay only the failing step's
51
+ // logs on error, rather than every line captured during the build.
52
+ std::deque<std::string> m_allLines;
53
+ size_t m_allLinesBytes = 0;
54
+ std::string m_pendingLine;
55
+ SHORT m_displayedLines = 0;
56
+ std::chrono::steady_clock::time_point m_lastRedraw{};
57
+ // Captured at construction so the destructor can detect destruction during exception unwinding.
58
+ int m_uncaughtExceptions = std::uncaught_exceptions();
59
};
60
} // namespace wsl::windows::wslc::services
src/windows/wslc/services/ChangeTerminalMode.h
new
+92
@@ -0,0 +1,92 @@
1
+/*++
2
+
3
+Copyright (c) Microsoft. All rights reserved.
4
+
5
+Module Name:
6
+
7
+ ChangeTerminalMode.h
8
+
9
+Abstract:
10
+
11
+ This file contains the ChangeTerminalMode definition.
12
+
13
+--*/
14
+#pragma once
15
+
16
+namespace wsl::windows::wslc::services {
17
+
18
+class ChangeTerminalMode
19
+{
20
+public:
21
+ NON_COPYABLE(ChangeTerminalMode);
22
+ NON_MOVABLE(ChangeTerminalMode);
23
+
24
+ ChangeTerminalMode(HANDLE console, bool cursorVisible) : m_console(console)
25
+ {
26
+ if (!wsl::windows::common::wslutil::IsConsoleHandle(console))
27
+ {
28
+ m_console = nullptr;
29
+ return;
30
+ }
31
+
32
+ THROW_IF_WIN32_BOOL_FALSE(GetConsoleCursorInfo(console, &m_originalCursorInfo));
33
+ CONSOLE_CURSOR_INFO newCursorInfo = m_originalCursorInfo;
34
+ newCursorInfo.bVisible = cursorVisible;
35
+ THROW_IF_WIN32_BOOL_FALSE(SetConsoleCursorInfo(console, &newCursorInfo));
36
+ }
37
+
38
+ ~ChangeTerminalMode()
39
+ {
40
+ if (m_console)
41
+ {
42
+ LOG_IF_WIN32_BOOL_FALSE(SetConsoleCursorInfo(m_console, &m_originalCursorInfo));
43
+ }
44
+ }
45
+
46
+ bool IsConsole() const
47
+ {
48
+ return m_console != nullptr;
49
+ }
50
+
51
+private:
52
+ HANDLE m_console{};
53
+ CONSOLE_CURSOR_INFO m_originalCursorInfo{};
54
+};
55
+
56
+// RAII helper that enables ENABLE_VIRTUAL_TERMINAL_PROCESSING on a console handle and
57
+// restores the original mode on destruction. No-op if the handle isn't a console or
58
+// VT processing is already enabled.
59
+class EnableVirtualTerminal
60
+{
61
+public:
62
+ NON_COPYABLE(EnableVirtualTerminal);
63
+ NON_MOVABLE(EnableVirtualTerminal);
64
+
65
+ explicit EnableVirtualTerminal(HANDLE console)
66
+ {
67
+ DWORD mode;
68
+ if (GetConsoleMode(console, &mode))
69
+ {
70
+ const DWORD newMode = mode | ENABLE_VIRTUAL_TERMINAL_PROCESSING;
71
+ if (newMode != mode && SetConsoleMode(console, newMode))
72
+ {
73
+ m_console = console;
74
+ m_originalMode = mode;
75
+ }
76
+ }
77
+ }
78
+
79
+ ~EnableVirtualTerminal()
80
+ {
81
+ if (m_console)
82
+ {
83
+ LOG_IF_WIN32_BOOL_FALSE(SetConsoleMode(m_console, m_originalMode));
84
+ }
85
+ }
86
+
87
+private:
88
+ HANDLE m_console = nullptr;
89
+ DWORD m_originalMode = 0;
90
+};
91
+
92
+} // namespace wsl::windows::wslc::services
src/windows/wslc/services/ImageProgressCallback.cpp
-22
@@ -20,28 +20,6 @@ Abstract:
20
namespace wsl::windows::wslc::services {
21
using namespace wsl::shared;
22
23
-ChangeTerminalMode::ChangeTerminalMode(HANDLE console, bool cursorVisible) : m_console(console)
24
-{
25
- if (!wsl::windows::common::wslutil::IsConsoleHandle(console))
26
- {
27
- m_console = nullptr;
28
- return;
29
- }
30
-
31
- THROW_IF_WIN32_BOOL_FALSE(GetConsoleCursorInfo(console, &m_originalCursorInfo));
32
- CONSOLE_CURSOR_INFO newCursorInfo = m_originalCursorInfo;
33
- newCursorInfo.bVisible = cursorVisible;
34
- THROW_IF_WIN32_BOOL_FALSE(SetConsoleCursorInfo(console, &newCursorInfo));
35
-}
36
-
37
-ChangeTerminalMode::~ChangeTerminalMode()
38
-{
39
- if (m_console)
40
- {
41
- LOG_IF_WIN32_BOOL_FALSE(SetConsoleCursorInfo(m_console, &m_originalCursorInfo));
42
- }
43
-}
44
-
23
auto ImageProgressCallback::MoveToLine(SHORT line)
24
{
25
if (line > 0)
src/windows/wslc/services/ImageProgressCallback.h
+2
-18
@@ -12,28 +12,11 @@ Abstract:
12
13
--*/
14
#pragma once
15
+#include "ChangeTerminalMode.h"
16
#include "SessionService.h"
17
18
namespace wsl::windows::wslc::services {
19
19
-class ChangeTerminalMode
20
-{
21
-public:
22
- NON_COPYABLE(ChangeTerminalMode);
23
- NON_MOVABLE(ChangeTerminalMode);
24
- ChangeTerminalMode(HANDLE console, bool cursorVisible);
25
- ~ChangeTerminalMode();
26
-
27
- bool IsConsole() const
28
- {
29
- return m_console != nullptr;
30
- }
31
-
32
-private:
33
- HANDLE m_console{};
34
- CONSOLE_CURSOR_INFO m_originalCursorInfo{};
35
-};
36
-
20
// TODO: Handle terminal resizes.
21
class DECLSPEC_UUID("7A1D3376-835A-471A-8DC9-23653D9962D0") ImageProgressCallback
22
: public Microsoft::WRL::RuntimeClass<Microsoft::WRL::RuntimeClassFlags<Microsoft::WRL::ClassicCom>, IProgressCallback, IFastRundown>
@@ -47,6 +30,7 @@ private:
30
std::wstring GenerateStatusLine(LPCSTR status, LPCSTR id, ULONGLONG current, ULONGLONG total, const CONSOLE_SCREEN_BUFFER_INFO& info);
31
std::map<std::string, SHORT> m_statuses;
32
SHORT m_currentLine = 0;
33
+ EnableVirtualTerminal m_vtMode{GetStdHandle(STD_OUTPUT_HANDLE)};
34
ChangeTerminalMode m_terminalMode{GetStdHandle(STD_OUTPUT_HANDLE), false};
35
};
36
} // namespace wsl::windows::wslc::services
\ No newline at end of file
src/windows/wslc/tasks/ImageTasks.cpp
+3
-2
@@ -83,8 +83,9 @@ void BuildImage(CLIExecutionContext& context)
83
WI_SetFlagIf(flags, WSLCBuildImageFlagsNoCache, context.Args.Contains(ArgType::NoCache));
84
WI_SetFlagIf(flags, WSLCBuildImageFlagsPull, context.Args.Contains(ArgType::BuildPull));
85
86
- BuildImageCallback callback;
87
- services::ImageService::Build(session, contextPath, tags, buildArgs, dockerfilePath, target, flags, &callback, context.CreateCancelEvent());
86
+ auto cancelEvent = context.CreateCancelEvent();
87
+ BuildImageCallback callback(cancelEvent, context.Args.Contains(ArgType::Verbose));
88
+ services::ImageService::Build(session, contextPath, tags, buildArgs, dockerfilePath, target, flags, &callback, cancelEvent);
89
}
90
91
void GetImages(CLIExecutionContext& context)
src/windows/wslcsession/WSLCSession.cpp
+15
-5
@@ -757,17 +757,19 @@ try
757
return " [" + name + "] ";
758
};
759
760
- auto reportProgress = [&](const std::string& message) {
760
+ auto reportProgress = [&](const std::string& message, const char* id = "") {
761
if (ProgressCallback != nullptr)
762
{
763
- THROW_IF_FAILED(ProgressCallback->OnProgress(message.c_str(), "", 0, 0));
763
+ THROW_IF_FAILED(ProgressCallback->OnProgress(message.c_str(), id, 0, 0));
764
}
765
};
766
767
+ static constexpr char c_logId[] = "log";
768
+
769
auto flushLine = [&]() {
770
if (needsNewline)
771
{
770
- reportProgress("\n");
772
+ reportProgress("\n", c_logId);
773
needsNewline = false;
774
}
775
};
@@ -835,13 +837,13 @@ try
837
// so it terminates/overwrites cleanly without a spurious prefix.
838
if (needsNewline && (decoded[0] == '\n' || decoded[0] == '\r'))
839
{
838
- reportProgress(decoded.substr(0, 1));
840
+ reportProgress(decoded.substr(0, 1), c_logId);
841
decoded.erase(0, 1);
842
}
843
844
if (!decoded.empty())
845
{
844
- reportProgress(IndentLines(decoded, logPrefix(it->second)));
846
+ reportProgress(IndentLines(decoded, logPrefix(it->second)), c_logId);
847
}
848
849
needsNewline = !decoded.empty() && decoded.back() != '\n';
@@ -931,6 +933,14 @@ try
933
934
int exitCode = buildProcess.Wait();
935
WSL_LOG("BuildImageComplete", TraceLoggingValue(exitCode, "ExitCode"));
936
+ // Strip \r from the error output. The captured docker output sometimes contains
937
+ // \r\n line endings (e.g., in the Dockerfile context BuildKit prints on failure).
938
+ // When the CRT writes stderr in text mode it translates each \n to \r\n, turning
939
+ // \r\n into \r\r\n. cmd.exe's 2> writes that as-is (one line break), but
940
+ // PowerShell's 2> treats it as two line breaks and double-spaces the output.
941
+ // Stripping \r normalizes to plain \n which becomes \r\n once via text-mode
942
+ // translation.
943
+ std::erase(allOutput, '\r');
944
THROW_HR_WITH_USER_ERROR_IF(E_FAIL, allOutput, exitCode != 0);
945
946
return S_OK;