Skip to content

Commit bccd2e2

Browse files
committed
Print build logs for only async deployments
1 parent 558cdc1 commit bccd2e2

2 files changed

Lines changed: 32 additions & 152 deletions

File tree

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

Lines changed: 13 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -6,17 +6,9 @@
66
"""
77
Build log formatter for `az webapp deploy` / `az functionapp deploy`.
88
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
9+
Renders a curated view of the Oryx build by default: milestones, aggregated package counts and
10+
a warning tally stay on screen, while ordinary chatter is shown on a single self-overwriting
11+
status line. --build-logs full shows verbatim output; --build-logs none hides build logs.
2012
"""
2113

2214
import re
@@ -30,13 +22,8 @@
3022
BUILD_LOGS_SUMMARY = "summary"
3123
BUILD_LOGS_NONE = "none"
3224

33-
# --- Patterns for classification ---
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.
25+
# Design: no denylist of "noise". A line is kept permanently only if it matches a milestone
26+
# (or is an aggregated summary); every other non-blank line is transient chatter.
4027

4128
# Patterns for counting packages
4229
_PIP_COLLECTING = re.compile(r'^\s*\[[\d:+]+\]\s*Collecting\s+(\S+)')
@@ -113,14 +100,10 @@ def __init__(self, verbosity=BUILD_LOGS_SUMMARY):
113100
self._warning_count = 0
114101

115102
def format_log_line(self, line): # pylint: disable=too-many-return-statements
116-
"""Classify a single log line for display.
117-
118-
Returns:
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).
103+
"""Classify a log line: returns (text, is_persistent), or None to omit.
104+
105+
is_persistent True keeps it on screen (milestones/summaries); False shows it on the
106+
transient status line. None omits blank lines or --build-logs none.
124107
"""
125108
if self.verbosity == BUILD_LOGS_FULL:
126109
return (line, True)
@@ -185,17 +168,9 @@ def get_warning_summary(self):
185168
class BuildLogRenderer:
186169
"""Render build logs as persistent milestones plus one self-overwriting status line.
187170
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.
171+
Chatter overwrites itself in place via carriage-return + clear-to-EOL (no vertical cursor
172+
moves), truncated to terminal width so it never wraps. On a non-TTY or --build-logs full,
173+
lines are printed plainly with no overwriting. All output goes through one stream.
199174
"""
200175

201176
_DIM = "\x1b[90m"
@@ -275,9 +250,7 @@ def finalize(self):
275250
self._stream.flush()
276251

277252
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)."""
253+
"""Briefly pause between batched lines so a poll streams in one-by-one. No-op unless interactive."""
281254
if self._interactive and self._PACE_SECONDS:
282255
time.sleep(self._PACE_SECONDS)
283256

src/azure-cli/azure/cli/command_modules/appservice/custom.py

Lines changed: 19 additions & 112 deletions
Original file line numberDiff line numberDiff line change
@@ -9886,11 +9886,7 @@ def _parse_log_time(log_time_str):
98869886

98879887

98889888
def _fetch_log_detail_items(details_url, headers):
9889-
"""Fetch and parse a deployment-log entry's details_url.
9890-
9891-
Returns a list of (detail_msg, detail_time, detail_id) tuples, or an empty list on any
9892-
failure (network error, non-200, or unexpected payload shape).
9893-
"""
9889+
"""Fetch a log entry's details_url as (detail_msg, detail_time, detail_id) tuples; [] on failure."""
98949890
import requests
98959891
from azure.cli.core.util import should_disable_connection_verify
98969892

@@ -9915,18 +9911,10 @@ def _fetch_log_detail_items(details_url, headers):
99159911

99169912
def _fetch_kudu_log_entries(cmd, resource_group_name, webapp_name, slot, deployment_id,
99179913
details_complete_ids=None):
9918-
"""Fetch raw log entries from Kudu deployment log API.
9919-
9920-
Returns a list of (message, log_time, entry_id, detail_items) tuples (empty if fetching
9921-
fails). Each detail_items is a list of (detail_msg, detail_time, detail_id) tuples fetched
9922-
from the entry's details_url.
9923-
9924-
details_complete_ids (optional set): used to avoid the N+1 network pattern when this is
9925-
called repeatedly while streaming. Every parent entry except the last one has final details,
9926-
so once an entry is no longer the tail it is recorded here and its details_url is not
9927-
re-fetched on subsequent polls. The last (in-progress) entry's details keep growing, so it is
9928-
always re-fetched. Skipped entries return an empty detail_items list. Pass None (the default,
9929-
used by the failure-path full-log fetch) to always fetch every entry's details.
9914+
"""Fetch Kudu deployment log entries as (message, log_time, entry_id, detail_items) tuples.
9915+
9916+
details_complete_ids (optional set) avoids the N+1 fetch while streaming: non-tail entries
9917+
have final details and are skipped on later polls. Pass None to fetch every entry's details.
99309918
"""
99319919
import requests
99329920
from azure.cli.core.util import should_disable_connection_verify
@@ -9956,8 +9944,7 @@ def _fetch_kudu_log_entries(cmd, resource_group_name, webapp_name, slot, deploym
99569944
details_url = entry.get('details_url')
99579945
is_last_entry = idx == total - 1
99589946

9959-
# Skip re-fetching details for entries whose details are already final.
9960-
# The last (in-progress) entry's details keep growing, so always re-fetch it.
9947+
# Skip details already finalized; the in-progress tail entry is always re-fetched.
99619948
skip_details = (
99629949
details_complete_ids is not None and
99639950
not is_last_entry and
@@ -9970,8 +9957,7 @@ def _fetch_kudu_log_entries(cmd, resource_group_name, webapp_name, slot, deploym
99709957

99719958
results.append((message, log_time, entry_id, detail_items))
99729959

9973-
# Once an entry is no longer the tail, its details are final; record it so future
9974-
# polls skip the redundant details_url fetch.
9960+
# Non-tail entries are final; record so later polls skip their details_url fetch.
99759961
if details_complete_ids is not None and not is_last_entry and entry_id:
99769962
details_complete_ids.add(entry_id)
99779963

@@ -9984,19 +9970,10 @@ def _fetch_kudu_log_entries(cmd, resource_group_name, webapp_name, slot, deploym
99849970
def _display_build_logs(cmd, resource_group_name, webapp_name, slot, deployment_id,
99859971
log_formatter=None, seen_log_ids=None, details_complete_ids=None,
99869972
renderer=None):
9987-
"""Fetch and display build logs from Kudu.
9988-
9989-
Handles all log display scenarios:
9990-
- Real-time streaming during BuildInProgress (called every 5s)
9991-
- Retrospective display after fast/sync builds complete
9992-
- Deduplication via seen_log_ids across multiple calls
9973+
"""Fetch and display Kudu build logs, deduping across calls.
99939974

9994-
seen_log_ids dedupes already-displayed lines; details_complete_ids avoids re-fetching the
9995-
details_url of entries whose details are already final (see _fetch_kudu_log_entries). Both
9996-
persist across calls for the lifetime of a single deployment poll loop.
9997-
9998-
Lines are routed through the formatter (summary/full/none modes) and the renderer
9999-
(persistent milestones vs the self-overwriting status line).
9975+
seen_log_ids skips already-shown lines; details_complete_ids skips finalized details_urls.
9976+
Lines route through the formatter (summary/full/none) and renderer (milestones vs status line).
100009977
"""
100019978
if seen_log_ids is None:
100029979
seen_log_ids = set()
@@ -10009,10 +9986,8 @@ def _display_build_logs(cmd, resource_group_name, webapp_name, slot, deployment_
100099986
if not entries:
100109987
return
100119988

10012-
# Reveal a batched poll one line at a time (renderer.pace() no-ops unless interactive).
10013-
# Persistent milestones are always paced (they are few and worth the reveal); high-volume
10014-
# transient chatter is capped so a large catch-up burst can't stall output for long, and
10015-
# can't exhaust the budget before the milestones that follow it.
9989+
# Reveal a batched poll one line at a time: always pace milestones, cap transient chatter so
9990+
# a large catch-up burst can't stall output (pace() no-ops unless interactive).
100169991
paced_chatter = 0
100179992
pace_limit = 40
100189993

@@ -10063,20 +10038,10 @@ def _fetch_full_build_logs(cmd, resource_group_name, webapp_name, slot, deployme
1006310038

1006410039

1006510040
def _emit_build_log_line(message, log_formatter, renderer, timestamp=None, indent=False):
10066-
"""Classify a raw build log line and route it to the renderer.
10067-
10068-
Milestones / aggregated summaries are emitted as persistent lines (kept on screen);
10069-
all other build chatter is shown on the self-overwriting status line. When log_formatter
10070-
is None the line is shown verbatim as persistent output.
10071-
10072-
Persistent lines use a consistent two-level hierarchy:
10073-
- top-level entries: "HH:MM:SS message"
10074-
- detail items: " message" (12-space indent)
10075-
- aggregated summaries already carry their own indentation.
10041+
"""Classify a build log line and route it to the renderer.
1007610042

10077-
Returns the kind of line emitted so callers can pace output: ``'persistent'`` for a
10078-
milestone/summary line, ``'transient'`` for build chatter on the status line, or None
10079-
if the line was omitted (blank line or --build-logs none).
10043+
Milestones/summaries are persistent (kept on screen); other chatter goes to the
10044+
self-overwriting status line. Returns 'persistent', 'transient', or None (omitted).
1008010045
"""
1008110046
if log_formatter is None:
1008210047
if indent or not timestamp:
@@ -10112,11 +10077,7 @@ def _emit_build_log_line(message, log_formatter, renderer, timestamp=None, inden
1011210077

1011310078
# pylint: disable=too-many-branches
1011410079
def _format_deployment_status_error(deployment_properties):
10115-
"""Extract a human-readable error line from a deployment-status payload's 'errors'.
10116-
10117-
Returns "Error: <message>\n" when a message is present, else "Extended ErrorCode:
10118-
<code>\n", or "" when there are no errors. Shared by the RuntimeFailed/BuildFailed paths.
10119-
"""
10080+
"""Extract an error line from a deployment-status payload's 'errors' ("" when none)."""
1012010081
errors = deployment_properties.get('errors')
1012110082
if not errors:
1012210083
return ""
@@ -10144,13 +10105,9 @@ def _poll_deployment_runtime_status(cmd, resource_group_name, webapp_name, slot,
1014410105
previous_status_text = None
1014510106
build_phase_start = None
1014610107

10147-
# Initialize the log formatter and renderer based on verbosity. The renderer keeps
10148-
# milestones/phase headers permanent and shows build chatter on a single self-
10149-
# overwriting status line on a TTY. For --build-logs full there is no overwriting
10150-
# (every line is printed verbatim); none hides build logs entirely.
10108+
# full -> verbatim lines; summary -> milestones + self-overwriting status line; none -> hidden.
1015110109
verbosity = build_logs or BUILD_LOGS_SUMMARY
1015210110
log_formatter = BuildLogFormatter(verbosity=verbosity)
10153-
# full -> plain line-by-line (no overwrite); otherwise auto-detect TTY (interactive=None).
1015410111
renderer = BuildLogRenderer(interactive=False if verbosity == "full" else None)
1015510112

1015610113
while time_elapsed < max_time_sec:
@@ -10174,10 +10131,8 @@ def _poll_deployment_runtime_status(cmd, resource_group_name, webapp_name, slot,
1017410131
build_phase_start = time.time()
1017510132
renderer.emit_persistent(f"{timestamp} {format_phase_header('Build Phase')}")
1017610133
elif deployment_status == "BuildSuccessful":
10177-
# Always fetch and display build logs on completion.
10178-
# For async (fast builds), real-time streaming may have missed most logs.
10179-
# For sync, build happened during POST so no logs were streamed at all.
10180-
# Pass seen_log_ids to avoid duplicating lines already shown in real-time.
10134+
# Fetch the full set on completion; fast builds may finish between polls
10135+
# so real-time streaming can miss lines. seen_log_ids prevents duplicates.
1018110136
if build_phase_start is None:
1018210137
renderer.emit_persistent(f"{timestamp} {format_phase_header('Build Phase')}")
1018310138
_display_build_logs(cmd, resource_group_name, webapp_name,
@@ -11628,49 +11583,6 @@ def _warmup_kudu_and_get_cookie_internal(params):
1162811583
return None
1162911584

1163011585

11631-
def _display_build_logs_on_sync_failure(params, scm_url):
11632-
"""For sync deployment failures, fetch build logs and return formatted error text.
11633-
11634-
This handles the case where the Kudu POST returns an error (e.g., 400) after the build
11635-
completed on the server. Without this, the customer only sees 'Status Code: 400' with no
11636-
build output.
11637-
11638-
Returns a formatted error string with logs included, or None if logs can't be fetched.
11639-
"""
11640-
import requests
11641-
from azure.cli.core.util import should_disable_connection_verify
11642-
from azure.cli.command_modules.appservice._build_log_formatter import format_build_failure_with_logs
11643-
11644-
try:
11645-
headers = get_scm_site_headers(params.cmd.cli_ctx, params.webapp_name,
11646-
params.resource_group_name, params.slot)
11647-
11648-
# Get the latest deployment ID
11649-
latest_url = scm_url + "/api/deployments/latest"
11650-
resp = requests.get(latest_url, headers=headers,
11651-
verify=not should_disable_connection_verify(), timeout=15)
11652-
if resp.status_code != 200:
11653-
return None
11654-
11655-
deployment_info = resp.json()
11656-
deployment_id = deployment_info.get('id')
11657-
if not deployment_id:
11658-
return None
11659-
11660-
# Fetch build logs
11661-
full_logs = _fetch_full_build_logs(params.cmd, params.resource_group_name,
11662-
params.webapp_name, params.slot, deployment_id)
11663-
if not full_logs:
11664-
return None
11665-
11666-
# Format in the same style as async BuildFailed
11667-
error_text = "Deployment failed because the build process failed\n"
11668-
return format_build_failure_with_logs(error_text, full_logs)
11669-
11670-
except Exception: # pylint: disable=broad-except
11671-
return None
11672-
11673-
1167411586
def _make_onedeploy_request(params):
1167511587
import requests
1167611588
from azure.cli.core.util import should_disable_connection_verify
@@ -11787,11 +11699,6 @@ def _make_onedeploy_request(params):
1178711699
scm_url = _get_scm_url(params.cmd, params.resource_group_name, params.webapp_name, params.slot)
1178811700
latest_deploymentinfo_url = scm_url + "/api/deployments/latest"
1178911701

11790-
# For sync deployment failures, fetch and display build logs in the error message
11791-
build_failure_text = _display_build_logs_on_sync_failure(params, scm_url)
11792-
if build_failure_text:
11793-
raise CLIError(build_failure_text)
11794-
1179511702
if _should_enrich_errors and response.status_code >= 400:
1179611703
logger.error("Deployment failed. Visit %s to get more information about your deployment.",
1179711704
latest_deploymentinfo_url)

0 commit comments

Comments
 (0)