root/build-tools/stx/utils.py
M. Vefa Bicakci 818830b25e Debian/stx: utils: Minor run_shell_cmd fix-ups
This commit fixes various minor issues in utils.py Python module's
run_shell_cmd function:

- Fix "local variable 'process' referenced before assignment" exception
  that can occur while handling exceptions raised by subprocess.Popen().
  This appears to only occur when a forked/child process cannot execute
  a program, which is a programming error, which in turn is a minor
  issue.

  Before this commit, attempting to run a non-existent program with, for
  example: 'run_shell_command("/bin/abc", ...)' would result in the
  exception "local variable 'process' referenced before assignment"
  while handling the exception "[Errno 2] No such file or directory:
  '/bin/abc'".

  With this commit, only the latter exception is reported, but in the
  following form, as part of a single/non-nested exception:

    [ Failed to execute command: "['/bin/abc']" Exception: "[Errno 2] \
      No such file or directory: '/bin/abc'" ]

- Avoid making Python print two tracebacks when handling exceptions
  raised by subprocess.Popen(). Logging a one-line description of the
  exception encountered by subprocess.Popen() (via "{e}", where "e" is
  an Exception object) is sufficient on its own to debug the encountered
  issue. (Please see above for an example.)

- Always log standard error of the command. While most of the messages
  logged to the standard error are debugging-oriented or point at minor
  issues, ignoring standard error still causes us to miss non-critical
  warning messages. In addition, change the log level for standard error
  output from "error" to "debug" to avoid panicking build system users
  due to the non-critical messages that will appear, such as the
  following:

  dpkg-architecture: warning: cannot determine CC system type, falling \
    back to default (native compilation)
  dpkg-source --before-build .
  dpkg-buildpackage: warning: building a source package without \
    cleaning up as you asked; it might contain undesired files
  dpkg-source -b .
  dpkg-genbuildinfo --build=source
  dpkg-genchanges --build=source >../mlnx-ofed-kernel_....changes
  dpkg-genchanges: info: not including original source code in upload

- In the logs, prefix the command's standard output with "stdout: " and
  its standard error with "stderr: ". This allows distinguishing between
  the command's messages emitted via standard output and standard error.

- Note that adding the "stdout: " prefix to each line of each command's
  standard output increases the log file's size by about 190 KiB,
  according to the following results from a fresh build with
  'build-pkgs -b std,rt -c -a':

    $ grep -e '2022-09-1[67] .*stdout: ' builder.log | wc -l
    24391 # num_lines
    $ echo $(( 24391 * 8 )) # i.e., num_lines * strlen("stdout: ")
    195128 # bytes

  Logging each command's standard error (along with prefixing each line
  with "stderr: ") adds about 1.87 MiB of output to the build logs,
  which corresponds to an increase of approximately 21 percent:

    $ grep -e '2022-09-1[67] .*stderr: ' builder.log | wc -c
    1963024
    $ grep -e '2022-09-1[67] ' builder.log | wc -c
    11164207
    $ echo 'scale=2; print 1963024.0/(11164207-1963024) * 100,"%\n";' \
        | bc
    21.00%

  Despite the increase in the log file size, logging the standard error
  uncovers some issues, mostly relating to the debian/changelog file
  formatting used by StarlingX developers, which are admittedly minor.
  Examples include:

  ... stderr: dpkg-genchanges: warning: debian/changelog(l...): \
    badly formatted trailer line
  ... stderr: dpkg-genchanges: warning: debian/changelog(l...): \
    found end of file where expected more change data or trailer

- Log the return code of the command if it fails. This provides
  additional information regarding why a command failed, in case the
  command's output is not sufficient to determine the reason.

- Prefer to log the command as a list/tuple if it is provided with that
  type, for easier correlation with the code and for consistency with
  the rest of the logging in the function.

- Improve logging and reduce the duplication involved in log message
  construction.

Verification
- 'build-pkgs -b rt,std -c -a' runs without issues with this patch, but
  emits additional output due to logging the standard error streams of
  executed commands.

Closes-Bug: 1989009
Closes-Bug: 1990177
Change-Id: I6b3c4dc70fb1404280ea15e8dcc573c83792f9b1
Signed-off-by: M. Vefa Bicakci <vefa.bicakci@windriver.com>
2022-09-19 17:01:13 +00:00

209 lines
6.4 KiB
Python
Executable File

# Copyright (c) 2021 Wind River Systems, Inc.
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
# http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.
#
# Copyright (C) 2021 Wind River Systems,Inc
import logging
import os
import pathlib
import subprocess
import urllib.parse
import urllib.request
CENGN_BASE = os.path.join(os.environ.get('CENGNURL'), "debian")
log_levels = {
'debug': logging.DEBUG,
'info': logging.INFO,
'warning': logging.WARNING,
'error': logging.ERROR,
'crit': logging.CRITICAL
}
def set_logger(logger, log_level='debug'):
logger.setLevel(log_levels[log_level])
class ColorFormatter(logging.Formatter):
FORMAT = ("%(asctime)s - $BOLD%(name)-s$RESET - %(levelname)s: %(message)s")
BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = list(range(8))
RESET_SEQ = "\033[0m"
COLOR_SEQ = "\033[1;%dm"
BOLD_SEQ = "\033[1m"
COLORS = {
'WARNING': YELLOW,
'INFO': GREEN,
'DEBUG': BLUE,
'ERROR': RED
}
def formatter_msg(self, msg, use_color=True):
if use_color:
msg = msg.replace("$RESET", self.RESET_SEQ)
msg = msg.replace("$BOLD", self.BOLD_SEQ)
else:
msg = msg.replace("$RESET", "").replace("$BOLD", "")
return msg
def __init__(self, use_color=True):
msg = self.formatter_msg(self.FORMAT, use_color)
logging.Formatter.__init__(self, msg)
self.use_color = use_color
def format(self, record):
lname = record.levelname
if self.use_color and lname in self.COLORS:
fcolor = 30 + self.COLORS[lname]
lncolor = self.COLOR_SEQ % fcolor + lname + self.RESET_SEQ
record.levelname = lncolor
return logging.Formatter.format(self, record)
# create log and console handler and set level
fh = logging.FileHandler('/localdisk/builder.log')
fh.setLevel(log_levels[log_level])
fh.setFormatter(ColorFormatter(use_color=False))
logger.addHandler(fh)
ch = logging.StreamHandler()
ch.setLevel(log_levels[log_level])
ch.setFormatter(ColorFormatter())
logger.addHandler(ch)
logger.propagate = 0
# Read file 'lst_file', sprip out blank lines and lines starting with '#'.
# Return the remaining lines as a list. Optionally subject the lines
# to additional processing via the entry_handler prior to inclusion in
# the list
def bc_safe_fetch(lst_file, entry_handler=None, entry_handler_arg=None):
entries = []
try:
with open(lst_file, 'r') as flist:
lines = list(line for line in (p.strip() for p in flist) if line)
except IOError as e:
logger.error(str(e))
except Exception as e:
logger.error(str(e))
else:
for entry in lines:
entry = entry.strip()
if entry.startswith('#'):
continue
if entry == "":
continue
if entry_handler:
if entry_handler_arg:
entries.extend(entry_handler(entry, entry_handler_arg))
else:
entries.extend(entry_handler(entry))
else:
entries.append(entry)
return entries
def limited_walk(dir, max_depth=1):
dir = dir.rstrip(os.path.sep)
assert os.path.isdir(dir)
num_sep_dir = dir.count(os.path.sep)
for root, dirs, files in os.walk(dir):
yield root, dirs, files
num_sep_root = root.count(os.path.sep)
if num_sep_dir + max_depth <= num_sep_root:
del dirs[:]
def run_shell_cmd(cmd, logger):
if type(cmd) is str:
shell = True
elif type(cmd) in (tuple, list):
shell = False
else:
raise Exception("Unrecognized 'cmd' type '%s'. Must be one of [str, list, tuple]." % (type(cmd)))
logger.info(f'[ Run - "{cmd}" ]')
try:
process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE,
universal_newlines=True, shell=shell)
except Exception as e:
msg = f'[ Failed to execute command: "{cmd}" Exception: "{e}" ]'
logger.error(msg)
# Suppress the original exception when raising our own exception.
# Syntax is acquired from: https://peps.python.org/pep-0409/#proposal
raise Exception(msg) from None
outs, errs = process.communicate()
for log in outs.strip().split("\n"):
log = log.strip()
if log:
logger.debug("stdout: %s", log)
for log in errs.strip().split("\n"):
log = log.strip()
if log:
logger.debug("stderr: %s", log)
if process.returncode != 0:
msg = f'[ Command failed with a non-zero return code: "{cmd}" return code: {process.returncode} ]'
logger.error(msg)
raise Exception(msg)
return outs.strip()
def url_to_cengn(url):
url_change = urllib.parse.urlparse(url)
url_path = pathlib.Path(url_change.path)
if url_change.netloc != '':
path = pathlib.Path(url_change.netloc, url_path.relative_to("/"))
else:
path = url_path
# FIXME: the ":" in a path is converted to "%25", after
# uploading to CENGN, the "%25" in the path is converted
# to "%2525".
return os.path.join(CENGN_BASE, path).replace("%25", "%2525")
def get_download_url(url, strategy):
alt_rt_url = None
cengn_url = url_to_cengn(url)
if strategy == "cengn":
rt_url = cengn_url
elif strategy == "upstream":
rt_url = url
elif strategy == "cengn_first":
try:
urllib.request.urlopen(cengn_url)
rt_url = cengn_url
alt_rt_url = url
except:
rt_url = url
elif strategy == "upstream_first":
try:
urllib.request.urlopen(url)
rt_url = url
alt_rt_url = cengn_url
except:
rt_url = cengn_url
else:
raise Exception(f'Invalid value "{strategy}" of CENGN_STRATEGY')
return (rt_url, alt_rt_url)