buildbot/utils.py

272 lines
10 KiB
Python
Raw Normal View History

2019-04-02 22:03:28 +08:00
#!/usr/bin/env python3
# -*- coding: utf-8 -*-
import subprocess
2019-04-09 15:43:17 +08:00
import logging, logging.handlers
from time import time, sleep
2019-04-02 22:03:28 +08:00
import re
from threading import Thread, Lock
2019-04-07 17:14:50 +08:00
from pathlib import Path
import os
import sys
import traceback
2019-04-02 22:03:28 +08:00
2019-04-07 17:14:50 +08:00
from config import PKG_COMPRESSION, SHELL_ARCH_ARM64, SHELL_ARCH_X64, \
CONTAINER_BUILDBOT_ROOT, ARCHS
2019-04-02 22:03:28 +08:00
2019-04-09 15:43:17 +08:00
logger = logging.getLogger(f'buildbot.{__name__}')
2019-04-02 22:03:28 +08:00
def background(func):
def wrapped(*args, **kwargs):
tr = Thread(target=func, args=args, kwargs=kwargs)
tr.daemon = True
tr.start()
return tr
return wrapped
def bash(cmdline, **kwargs):
assert type(cmdline) is str
2019-04-07 17:14:50 +08:00
logger.info(f'bash: {cmdline}, kwargs: {kwargs}')
2019-04-02 22:03:28 +08:00
return(run_cmd(['/bin/bash', '-x', '-e', '-c', cmdline], **kwargs))
2019-04-07 17:14:50 +08:00
def mon_bash(cmdline, cwd=None, minutes=30, **kwargs):
assert type(minutes) is int and minutes >= 1
return bash(cmdline, cwd=cwd, keepalive=True, KEEPALIVE_TIMEOUT=60,
RUN_CMD_TIMEOUT=minutes*60, **kwargs)
2019-04-02 22:03:28 +08:00
2019-04-07 17:14:50 +08:00
def nspawn_shell(arch, cmdline, cwd=None, **kwargs):
root = Path(CONTAINER_BUILDBOT_ROOT)
if cwd:
cwd = root / cwd
else:
cwd = root
if arch in ('aarch64', 'arm64'):
2019-04-09 15:43:17 +08:00
return bash(SHELL_ARCH_ARM64.format(command=f'cd \"{cwd}\" || exit 1; {cmdline}'), **kwargs)
2019-04-07 17:14:50 +08:00
elif arch in ('x64', 'x86', 'x86_64'):
2019-04-09 15:43:17 +08:00
return bash(SHELL_ARCH_X64.format(command=f'cd \"{cwd}\" || exit 1; {cmdline}'), **kwargs)
2019-04-07 17:14:50 +08:00
raise TypeError('nspawn_shell: wrong arch')
def mon_nspawn_shell(arch, cmdline, cwd, minutes=30, **kwargs):
assert type(minutes) is int and minutes >= 1
return nspawn_shell(arch, cmdline, cwd=cwd, keepalive=True, KEEPALIVE_TIMEOUT=60,
RUN_CMD_TIMEOUT=minutes*60, **kwargs)
def run_cmd(cmd, cwd=None, keepalive=False, KEEPALIVE_TIMEOUT=30, RUN_CMD_TIMEOUT=60,
logfile=None, short_return=False):
2019-04-03 18:10:00 +08:00
logger.debug('run_cmd: %s', cmd)
2019-04-02 22:03:28 +08:00
RUN_CMD_LOOP_TIME = KEEPALIVE_TIMEOUT - 1 if KEEPALIVE_TIMEOUT >= 10 else 5
stopped = False
last_read = [int(time()), ""]
2019-04-07 17:14:50 +08:00
class Output(list):
2019-04-09 15:43:17 +08:00
def __init__(self, logfile=None, short_return=False):
super().__init__()
2019-04-07 17:14:50 +08:00
self.__short_return = short_return
if logfile:
assert issubclass(type(logfile), os.PathLike)
self.__file = open(logfile, 'w')
else:
self.__file = None
2019-04-09 15:43:17 +08:00
def append(self, mystring):
if not self.__short_return:
super().append(mystring)
if self.__file and type(mystring) is str:
self.__file.write(mystring)
def __enter__(self):
2019-04-07 22:19:06 +08:00
return self
2019-04-07 17:14:50 +08:00
def __exit__(self, type, value, traceback):
if self.__file:
self.__file.close()
2019-04-02 22:03:28 +08:00
stdout_lock = Lock()
2019-04-07 17:14:50 +08:00
with Output(logfile=logfile, short_return=short_return) as output:
@background
def check_stdout(stdout):
nonlocal stopped, last_read, output
stdout_lock.acquire()
2019-04-02 22:03:28 +08:00
last_read_time = int(time())
2019-04-07 17:14:50 +08:00
while stopped is False:
line = stdout.readline(4096)
last_read_time = int(time())
logger.debug(line)
output.append(line)
last_read[0] = last_read_time
last_read[1] = line
stdout_lock.release()
p = subprocess.Popen(cmd, cwd=cwd, stdin=subprocess.PIPE, stdout=subprocess.PIPE,
stderr=subprocess.STDOUT, encoding='utf-8')
check_stdout(p.stdout)
process_start = int(time())
while True:
try:
p.wait(timeout=RUN_CMD_LOOP_TIME)
except subprocess.TimeoutExpired:
time_passed = int(time()) - last_read[0]
if time_passed >= KEEPALIVE_TIMEOUT*2:
logger.info('Timeout expired. No action.')
output.append('+ Buildbot: Timeout expired. No action.\n')
elif time_passed >= KEEPALIVE_TIMEOUT:
if keepalive:
logger.info('Timeout expired, writing nl')
output.append('+ Buildbot: Timeout expired, writing nl\n')
p.stdin.write('\n')
p.stdin.flush()
else:
logger.info('Timeout expired, not writing nl')
output.append('+ Buildbot: Timeout expired, not writing nl\n')
if int(time()) - process_start >= RUN_CMD_TIMEOUT:
stopped = True
logger.error('Process timeout expired, terminating.')
output.append('+ Buildbot: Process timeout expired, terminating.\n')
p.terminate()
try:
p.wait(timeout=10)
except subprocess.TimeoutExpired:
logger.error('Cannot terminate, killing.')
output.append('+ Buildbot: Cannot terminate, killing.\n')
p.kill()
break
else:
2019-04-09 15:43:17 +08:00
# sometimes the process ended too quickly and stdout is not captured
sleep(0.1)
2019-04-02 22:03:28 +08:00
stopped = True
break
2019-04-07 17:14:50 +08:00
code = p.returncode
stdout_lock.acquire(10)
outstr = ''.join(output)
2019-04-02 22:03:28 +08:00
if code != 0:
raise subprocess.CalledProcessError(code, cmd, outstr)
return outstr
2019-04-03 18:10:00 +08:00
# pyalpm is an alternative
# due to lack of documentation i'll consider this later.
def vercmp(ver1, ver2):
'''
compare ver1 and ver2, return 1, -1, 0
see https://www.archlinux.org/pacman/vercmp.8.html
'''
res = run_cmd(['vercmp', str(ver1), str(ver2)])
res = res.strip()
if res in ('-1', '0', '1'):
return int(res)
2019-04-02 22:03:28 +08:00
class Pkg:
2019-04-03 18:10:00 +08:00
def __init__(self, pkgname, pkgver, pkgrel, arch, fname):
2019-04-02 22:03:28 +08:00
self.pkgname = pkgname
self.pkgver = pkgver
self.pkgrel = pkgrel
self.arch = arch
2019-04-03 18:10:00 +08:00
self.fname = fname
self.ver = f'{self.pkgver}-{self.pkgrel}'
def __eq__(self, ver2):
if vercmp(self.ver, ver2.ver) == 0:
return True
else:
return False
def __ge__(self, ver2):
return self > ver2 or self == ver2
def __gt__(self, ver2):
if vercmp(self.ver, ver2.ver) == 1:
return True
else:
return False
def __le__(self, ver2):
return self < ver2 or self == ver2
def __lt__(self, ver2):
if vercmp(self.ver, ver2.ver) == -1:
return True
else:
return False
def __repr__(self):
return f'Pkg({self.pkgname}, {self.ver}, {self.arch})'
2019-04-02 22:03:28 +08:00
def get_pkg_details_from_name(name):
2019-04-03 12:39:33 +08:00
assert type(name) is str
2019-04-02 22:03:28 +08:00
if name.endswith(f'pkg.tar.{PKG_COMPRESSION}'):
2019-04-02 22:29:38 +08:00
m = re.match(r'(.+)-([^-]+)-([^-]+)-([^-]+)\.pkg\.tar\.\w+', name)
assert m and m.groups() and len(m.groups()) == 4
(pkgname, pkgver, pkgrel, arch) = m.groups()
2019-04-03 18:10:00 +08:00
return Pkg(pkgname, pkgver, pkgrel, arch, name)
2019-04-02 22:03:28 +08:00
2019-04-07 17:14:50 +08:00
def get_arch_from_pkgbuild(fpath):
assert issubclass(type(fpath), os.PathLike)
with open(fpath, 'r') as f:
2019-04-07 22:19:06 +08:00
for line in f.read().split('\n'):
2019-04-07 17:14:50 +08:00
if line.startswith('arch='):
matches = re.findall('[\'\"]([^\'\"]+)[\'\"]', line)
if not matches:
raise TypeError('Unexpected PKGBUILD format')
assert not [None for match in matches if match not in ARCHS]
return matches
raise TypeError('Unexpected PKGBUILD')
def print_exc_plus():
2019-04-09 15:43:17 +08:00
logger.log(49, format_exc_plus())
def format_exc_plus():
"""
Print the usual traceback information, followed by a listing of all the
local variables in each frame.
from Python Cookbook by David Ascher, Alex Martelli
"""
2019-04-09 15:43:17 +08:00
ret = str()
tb = sys.exc_info()[2]
while True:
if not tb.tb_next:
break
tb = tb.tb_next
stack = []
f = tb.tb_frame
while f:
stack.append(f)
f = f.f_back
stack.reverse()
2019-04-09 15:43:17 +08:00
ret += traceback.format_exc()
ret += "\nLocals by frame, innermost last\n"
for frame in stack:
2019-04-09 15:43:17 +08:00
ret += "Frame %s in %s at line %s\n" % (frame.f_code.co_name,
frame.f_code.co_filename,
frame.f_lineno)
for key, value in frame.f_locals.items( ):
2019-04-09 15:43:17 +08:00
ret += "\t%20s = " % key
# We have to be VERY careful not to cause a new error in our error
# printer! Calling str( ) on an unknown object could cause an
# error we don't want, so we must use try/except to catch it --
# we can't stop it from happening, but we can and should
# stop it from propagating if it does happen!
try:
2019-04-09 15:43:17 +08:00
ret += str(value)
except:
2019-04-09 15:43:17 +08:00
ret += "<ERROR WHILE PRINTING VALUE>"
ret += '\n'
return ret
def configure_logger(logger, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
level=logging.INFO, logfile=None, flevel=logging.INFO, rotate_size=None):
class ExceptionFormatter(logging.Formatter):
def format(self, record):
if record.levelno == 49:
record.msg = 'Exception caught.\nPrinting stack traceback\n' + record.msg
return super().format(record)
logger.setLevel(level)
formatter = ExceptionFormatter(fmt=format)
logging.addLevelName(49, 'Exception')
# create file handler
if logfile:
assert type(logfile) is str
if rotate_size and type(rotate_size) is int and rotate_size >= 1000:
fh = logging.handlers.RotatingFileHandler(logfile, mode='a',
maxBytes=rotate_size, backupCount=8)
else:
fh = logging.FileHandler(logfile)
fh.setLevel(flevel)
fh.setFormatter(formatter)
logger.addHandler(fh)
# create console handler
ch = logging.StreamHandler()
ch.setLevel(level)
ch.setFormatter(formatter)
logger.addHandler(ch)