Skip to content

Commit 558cdc1

Browse files
PriyaCh1144PriyaCh1144
committed
Stream build logs during deployment
1 parent 0d8de31 commit 558cdc1

3 files changed

Lines changed: 708 additions & 233 deletions

File tree

‎src/azure-cli/azure/cli/command_modules/appservice/_build_log_formatter.py‎

Lines changed: 163 additions & 153 deletions
Original file line numberDiff line numberDiff line change
@@ -6,17 +6,23 @@
66
"""
77
Build log formatter for `az webapp deploy` / `az functionapp deploy`.
88
9-
Provides intelligent log filtering that shows a clean summary by default,
10-
with full verbosity available via --build-logs full.
11-
12-
Log levels:
13-
- PHASE: Major deployment phases (always shown)
14-
- INFO: Important milestones (shown in summary + full)
15-
- DETAIL: Individual package lines, SDK metadata (shown only in full)
16-
- WARNING: Deprecation notices, pip warnings (aggregated in summary, shown in full)
9+
Renders a clean, curated view of the Oryx build by default: deterministic milestones,
10+
aggregated package counts and a warning tally are kept permanently on screen, while
11+
ordinary build chatter is shown on a single self-overwriting status line (the current
12+
line is replaced in place by the next -- like a progress line). Full verbatim output is
13+
available via --build-logs full; --build-logs none hides build logs entirely.
14+
15+
Classification (summary mode):
16+
- PERSISTENT: stack/version detection, phase milestones, "Installed N packages"
17+
- TRANSIENT: package downloads, oryx/SDK metadata, warnings, other chatter
18+
(shown on the self-overwriting status line; warnings are also counted)
19+
- OMITTED: blank lines
1720
"""
1821

1922
import re
23+
import shutil
24+
import sys
25+
import time
2026

2127

2228
# Log verbosity levels
@@ -25,90 +31,12 @@
2531
BUILD_LOGS_NONE = "none"
2632

2733
# --- Patterns for classification ---
28-
29-
# Oryx internal metadata lines (hidden in summary mode)
30-
_ORYX_METADATA_PATTERNS = [
31-
re.compile(r'^\s*(Operation performed by Microsoft Oryx)'),
32-
re.compile(r'^\s*(You can report issues at)'),
33-
re.compile(r'^\s*(Oryx Version:)'),
34-
re.compile(r'^\s*(Build Operation ID:)'),
35-
re.compile(r'^\s*(Repository Commit\s*:)'),
36-
re.compile(r'^\s*(OS Type\s*:)'),
37-
re.compile(r'^\s*(Image Type\s*:)'),
38-
re.compile(r'^\s*(Primary SDK Storage URL:)'),
39-
re.compile(r'^\s*(Backup SDK Storage URL:)'),
40-
re.compile(r'^\s*(ACR SDK Registry URL:)'),
41-
re.compile(r'^\s*(SDK provider status:)'),
42-
re.compile(r'^\s*(External ACR SDK provider)'),
43-
re.compile(r'^\s*(External SDK provider)'),
44-
re.compile(r'^\s*(Direct ACR SDK provider)'),
45-
re.compile(r'^\s*(Blob SDK provider)'),
46-
re.compile(r'^\s*(External ACR provider resolved)'),
47-
re.compile(r'^\s*(Version resolved using)'),
48-
re.compile(r'^\s*(Requesting SDK from ACR)'),
49-
re.compile(r'^\s*(Successfully pulled SDK from ACR)'),
50-
re.compile(r'^\s*(SDK for .* fetched via)'),
51-
re.compile(r'^\s*(Requesting metadata for platform)'),
52-
re.compile(r'^\s*(Not a vso image)'),
53-
re.compile(r'^\s*(Creating directory for command manifest)'),
54-
re.compile(r'^\s*(Removing existing manifest file)'),
55-
re.compile(r'^\s*(Creating a manifest file)'),
56-
re.compile(r'^\s*(Manifest file created)'),
57-
re.compile(r'^\s*(Copying \.ostype)'),
58-
re.compile(r'^\s*(Node Build Command Manifest)'),
59-
# .NET first-run banner (noisy, not useful for deployment)
60-
re.compile(r'^\s*(Welcome to \.NET)'),
61-
re.compile(r'^\s*-{5,}$'), # separator lines like "---------------------"
62-
re.compile(r'^\s*(SDK Version:)'),
63-
re.compile(r'^\s*(Telemetry)$'),
64-
re.compile(r'^\s*(The \.NET tools collect usage data)'),
65-
re.compile(r'^\s*(Read more about \.NET CLI Tools telemetry)'),
66-
re.compile(r'^\s*(Installed an ASP\.NET Core HTTPS)'),
67-
re.compile(r'^\s*(To trust the certificate)'),
68-
re.compile(r'^\s*(Learn about HTTPS)'),
69-
re.compile(r'^\s*(Write your first app)'),
70-
re.compile(r'^\s*(Find out what.s new)'),
71-
re.compile(r'^\s*(Explore documentation)'),
72-
re.compile(r'^\s*(Report issues and find source)'),
73-
re.compile(r'^\s*(Use .dotnet --help.)'),
74-
re.compile(r'^\s*={5,}$'), # separator lines like "==================="
75-
# Kudu internal deployment metadata
76-
re.compile(r'^\s*(PreDeployment:)'),
77-
re.compile(r'^\s*(Repository path is)'),
78-
re.compile(r'^\s*(Using standard output preparation)'),
79-
re.compile(r'^\s*(Total time for destination directory preparation)'),
80-
# Kudu build summary noise (0 errors/warnings not useful on success)
81-
re.compile(r'^\s*(Found \d+ issue)'),
82-
re.compile(r'^\s*(Build Summary)'),
83-
re.compile(r'^\s*(Errors \(\d+\))'),
84-
re.compile(r'^\s*(Warnings \(\d+\))'),
85-
re.compile(r'^\s*(Parsing the build logs)'),
86-
re.compile(r'^\s*(Preparing deployment for commit id)'),
87-
# Kudu post-build noise
88-
re.compile(r'^\s*(Updating submodules)'),
89-
re.compile(r'^\s*(Triggering container recycle)'),
90-
re.compile(r'^\s*(Generating summary of Oryx build)'),
91-
]
92-
93-
# Package download/cache lines (suppressed, counted instead)
94-
_PACKAGE_LINE_PATTERNS = [
95-
re.compile(r'^\s*\[[\d:+]+\]\s*(Collecting|Using cached|Downloading|Using)'),
96-
re.compile(r'^\s*\[[\d:+]+\]\s*(Successfully installed)'),
97-
re.compile(r'^\s*(npm warn|npm notice)'),
98-
re.compile(r'^\s*added \d+ packages'),
99-
re.compile(r'^\s*-\s+(Locking|Installing|Downloading)\s+\S+'), # composer package ops
100-
re.compile(r'^\s*\d+/\d+\s*\[[\s=>-]*\]\s*\d+%'), # composer progress bars (X/Y format)
101-
re.compile(r'^\s*\d+\s*\[[->=<>\s]*\]'), # composer progress bars (single number format)
102-
re.compile(r'^\s*Loading composer repositories'),
103-
re.compile(r'^\s*(Updating dependencies|Lock file operations:)'),
104-
re.compile(r'^\s*(Installing dependencies from lock file)'),
105-
re.compile(r'^\s*(Writing lock file)'),
106-
re.compile(r'^\s*Package operations:'),
107-
re.compile(r'^\s*Generating autoload files'),
108-
re.compile(r'^\s*\d+ package suggestions were added'),
109-
re.compile(r'^\s*\d+ package you are using is looking for funding'),
110-
re.compile(r'^\s*Use the `composer'),
111-
]
34+
#
35+
# Design: we intentionally do NOT keep a denylist of "noise" lines. A line is shown
36+
# *permanently* only if it matches a deterministic milestone (or is an aggregated
37+
# package summary); every other non-blank line is treated as transient chatter shown on
38+
# the self-overwriting status line (still fully available via --build-logs full). This
39+
# avoids the brittle per-stack denylists that previously needed constant maintenance.
11240

11341
# Patterns for counting packages
11442
_PIP_COLLECTING = re.compile(r'^\s*\[[\d:+]+\]\s*Collecting\s+(\S+)')
@@ -182,97 +110,65 @@ class BuildLogFormatter:
182110
def __init__(self, verbosity=BUILD_LOGS_SUMMARY):
183111
self.verbosity = verbosity
184112
self._package_count = 0
185-
self._packages_collecting = False
186-
self._packages_installing = False
187113
self._warning_count = 0
188-
self._suppressed_lines = [] # stored for auto-expand on failure
189114

190-
def format_log_line(self, line):
191-
"""Process a single log line and return formatted output or None to suppress.
115+
def format_log_line(self, line): # pylint: disable=too-many-return-statements
116+
"""Classify a single log line for display.
192117
193118
Returns:
194-
str or None: The formatted line to display, or None if suppressed.
119+
(text, is_persistent): ``text`` is the string to display; ``is_persistent``
120+
True means keep it permanently on screen (milestones, aggregated
121+
summaries), False means it is transient build chatter shown on the
122+
self-overwriting status line.
123+
None: omit the line entirely (blank lines, or --build-logs none).
195124
"""
196125
if self.verbosity == BUILD_LOGS_FULL:
197-
return line
126+
return (line, True)
198127
if self.verbosity == BUILD_LOGS_NONE:
199-
self._suppressed_lines.append(line)
200128
return None
201129

202-
# Summary mode: intelligent filtering
130+
# Summary mode: milestones/aggregates are persistent; everything else (warnings,
131+
# package chatter, oryx metadata, unknown lines) is transient. Blank lines drop.
203132
stripped = line.strip()
204133
if not stripped:
205134
return None
206135

207-
# Check if it's a warning line - aggregate it
208-
if stripped.startswith('npm warn'):
209-
self._warning_count += 1
210-
self._suppressed_lines.append(line)
211-
return None
212-
136+
# Warnings (incl. "npm warn ...") are counted, then shown transiently.
213137
for pattern in _WARNING_PATTERNS:
214138
if pattern.match(stripped):
215139
self._warning_count += 1
216-
self._suppressed_lines.append(line)
217-
return None
140+
return (line, False)
218141

219-
# Check if it's a package download/install line - count it
142+
# pip "Collecting <pkg>": count for the install summary, then scroll transiently.
220143
if _PIP_COLLECTING.match(stripped):
221144
self._package_count += 1
222-
if not self._packages_collecting:
223-
self._packages_collecting = True
224-
self._suppressed_lines.append(line)
225-
return None
226-
self._suppressed_lines.append(line)
227-
return None
228-
229-
if _PIP_CACHED.match(stripped):
230-
self._suppressed_lines.append(line)
231-
return None
145+
return (line, False)
232146

233-
if _PIP_INSTALLING.match(stripped):
234-
self._packages_installing = True
235-
self._suppressed_lines.append(line)
236-
return None
147+
if _PIP_CACHED.match(stripped) or _PIP_INSTALLING.match(stripped):
148+
return (line, False)
237149

238-
# "Successfully installed ..." - emit summary instead
150+
# "Successfully installed ..." -> aggregated persistent milestone.
239151
pip_installed_match = _PIP_INSTALLED.match(stripped)
240152
if pip_installed_match:
241153
pkg_list = pip_installed_match.group(1)
242154
count = len(pkg_list.split())
243-
self._suppressed_lines.append(line)
244155
result = self._emit_package_summary(count)
245-
self._packages_collecting = False
246-
self._packages_installing = False
247156
self._package_count = 0
248-
return result
157+
return (result, True)
249158

250-
# npm "added N packages"
159+
# npm "added N packages" -> aggregated persistent milestone.
251160
npm_match = _NPM_ADDED.match(stripped)
252161
if npm_match:
253162
count = int(npm_match.group(1))
254-
self._suppressed_lines.append(line)
255-
return f" Installed {count} packages\n"
256-
257-
# Check for Oryx metadata lines - suppress
258-
for pattern in _ORYX_METADATA_PATTERNS:
259-
if pattern.match(stripped):
260-
self._suppressed_lines.append(line)
261-
return None
163+
return (f" Installed {count} packages\n", True)
262164

263-
# Check for other package-level detail lines
264-
for pattern in _PACKAGE_LINE_PATTERNS:
265-
if pattern.match(stripped):
266-
self._suppressed_lines.append(line)
267-
return None
268-
269-
# Check if it's a milestone line - always show
165+
# Deterministic milestones -> persistent.
270166
for pattern in _MILESTONE_PATTERNS:
271167
if pattern.match(stripped):
272-
return line
168+
return (line, True)
273169

274-
# Default: show lines that aren't matched by any suppression pattern
275-
return line
170+
# Everything else is build chatter -> transient rolling window.
171+
return (line, False)
276172

277173
def _emit_package_summary(self, installed_count):
278174
"""Generate summary line for package installation."""
@@ -282,11 +178,125 @@ def _emit_package_summary(self, installed_count):
282178
def get_warning_summary(self):
283179
"""Get aggregated warning summary. Call at end of build phase."""
284180
if self._warning_count > 0:
285-
return (f" [!] {self._warning_count} warning(s) "
286-
f"(use --build-logs full to view)\n")
181+
return f" [!] {self._warning_count} warning(s)\n"
287182
return None
288183

289184

185+
class BuildLogRenderer:
186+
"""Render build logs as persistent milestones plus one self-overwriting status line.
187+
188+
Milestones and phase headers are printed permanently (each on its own line). Ordinary
189+
build chatter is shown on a single transient line that overwrites itself in place as new
190+
chatter arrives -- like a progress/status line. Only a carriage return + clear-to-end-of-
191+
line are used (no vertical cursor movement), so the display cannot desync even for very
192+
long or very rapid output; each transient line is also truncated to the terminal width so
193+
it never wraps.
194+
195+
On a non-TTY -- or when interactive rendering is disabled (``--build-logs full``) -- there
196+
is no overwriting: persistent and transient lines are all printed plainly so nothing is
197+
lost. All output goes to a single stream (stdout by default); callers must route every
198+
build-phase line through this renderer so no other writer corrupts the status line.
199+
"""
200+
201+
_DIM = "\x1b[90m"
202+
_RESET = "\x1b[0m"
203+
_CLEAR_LINE = "\r\x1b[2K"
204+
_TRANSIENT_INDENT = " " # align the moving line under detail milestones
205+
_PACE_SECONDS = 0.1 # small per-line delay so a batched reveal "streams" in (TTY only)
206+
207+
def __init__(self, stream=None, interactive=None):
208+
if interactive is None:
209+
probe = stream if stream is not None else sys.stdout
210+
try:
211+
interactive = bool(probe.isatty())
212+
except Exception: # pylint: disable=broad-except
213+
interactive = False
214+
self._interactive = interactive
215+
# On legacy Windows consoles colorama makes the ANSI escapes work; only needed
216+
# when we own the real stdout (tests pass a StringIO and don't need it).
217+
if self._interactive and stream is None:
218+
try:
219+
import colorama
220+
if hasattr(colorama, 'just_fix_windows_console'):
221+
colorama.just_fix_windows_console()
222+
else:
223+
colorama.init()
224+
except Exception: # pylint: disable=broad-except
225+
pass
226+
self._stream = stream if stream is not None else sys.stdout
227+
# True while a transient status line is on screen without a trailing newline.
228+
self._active = False
229+
230+
def _width(self):
231+
try:
232+
return shutil.get_terminal_size((100, 24)).columns
233+
except Exception: # pylint: disable=broad-except
234+
return 100
235+
236+
def _truncate(self, text):
237+
# Collapse to a single physical row and clip to the terminal width so the status
238+
# line never wraps (wrapping would leave stranded rows the clear cannot reach).
239+
text = text.replace('\r', ' ').replace('\n', ' ').rstrip()
240+
width = max(self._width() - 1, 20)
241+
if len(text) > width:
242+
text = text[:width - 1] + '\u2026'
243+
return text
244+
245+
def _clear_active(self):
246+
if self._active:
247+
self._stream.write(self._CLEAR_LINE)
248+
self._active = False
249+
250+
def emit_persistent(self, text):
251+
"""Print a line that stays on screen permanently (clears any active status line)."""
252+
text = text.rstrip('\n')
253+
self._clear_active()
254+
self._stream.write(text + '\n')
255+
self._stream.flush()
256+
257+
def emit_transient(self, text):
258+
"""Show a chatter line on the single self-overwriting status line."""
259+
if not self._interactive:
260+
line = text.rstrip('\n')
261+
if line.strip():
262+
self._stream.write(line + '\n')
263+
self._stream.flush()
264+
return
265+
line = self._truncate(self._TRANSIENT_INDENT + text)
266+
if not line.strip():
267+
return
268+
self._stream.write(self._CLEAR_LINE + self._DIM + line + self._RESET)
269+
self._stream.flush()
270+
self._active = True
271+
272+
def finalize(self):
273+
"""Erase the active status line, leaving only the persistent lines."""
274+
self._clear_active()
275+
self._stream.flush()
276+
277+
def pace(self):
278+
"""Briefly pause between batched lines so a poll's worth of output streams in
279+
one-by-one instead of appearing all at once. No-op unless interactive (so
280+
--build-logs full, CI and piped output stay instant)."""
281+
if self._interactive and self._PACE_SECONDS:
282+
time.sleep(self._PACE_SECONDS)
283+
284+
285+
def format_phase_header(label, width=50):
286+
"""Render a phase header with the label centered in a band of dashes.
287+
288+
e.g. format_phase_header("Build Phase") ->
289+
"------------------- Build Phase -------------------"
290+
"""
291+
label = " {} ".format(label.strip())
292+
if len(label) >= width:
293+
return label.strip()
294+
dashes = width - len(label)
295+
left = dashes // 2
296+
right = dashes - left
297+
return ("-" * left) + label + ("-" * right)
298+
299+
290300
def format_final_url(url):
291301
"""Format the final app URL to stand out in terminal output."""
292302
separator = "-" * 50
@@ -298,11 +308,11 @@ def format_final_url(url):
298308
)
299309

300310

301-
def format_build_failure_with_logs(error_text, suppressed_logs):
302-
"""On build failure, auto-expand suppressed logs for debugging."""
311+
def format_build_failure_with_logs(error_text, log_lines):
312+
"""On build failure, dump the full build logs for debugging, followed by the error."""
303313
output = []
304314
output.append("\n-- Build Failed -- Showing full build logs for debugging --\n\n")
305-
for log_line in suppressed_logs:
315+
for log_line in log_lines:
306316
output.append(log_line if log_line.endswith('\n') else log_line + '\n')
307317
output.append("\n-- End of build logs --\n\n")
308318
output.append(error_text)

0 commit comments

Comments
 (0)