buildbot/utils.py

306 lines
11 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, \
2019-04-09 20:48:37 +08:00
SHELL_ARM64_ADDITIONAL, SHELL_TRAP, \
2019-04-07 17:14:50 +08:00
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-11 14:55:42 +08:00
logger.debug(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-09 20:48:37 +08:00
def mon_bash(cmdline, seconds=60*30, **kwargs):
assert type(seconds) is int and seconds >= 1
return bash(cmdline, keepalive=True, KEEPALIVE_TIMEOUT=60,
RUN_CMD_TIMEOUT=seconds, **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
2019-04-11 14:55:42 +08:00
logger.debug(f'bash_{arch}: {cmdline}, cwd: {cwd}, kwargs: {kwargs}')
2019-04-07 17:14:50 +08:00
if arch in ('aarch64', 'arm64'):
2019-04-09 20:48:37 +08:00
command=f'{SHELL_ARM64_ADDITIONAL}; {SHELL_TRAP}; cd \'{cwd}\'; {cmdline}'
ret = run_cmd(SHELL_ARCH_ARM64 + [command,], **kwargs)
2019-04-07 17:14:50 +08:00
elif arch in ('x64', 'x86', 'x86_64'):
2019-04-09 20:48:37 +08:00
command=f'{SHELL_TRAP}; cd \'{cwd}\'; {cmdline}'
ret = run_cmd(SHELL_ARCH_X64 + [command,], **kwargs)
else:
raise TypeError('nspawn_shell: wrong arch')
if not ret.endswith('++ exit 0\n'):
raise subprocess.CalledProcessError(1, cmdline, ret)
return ret
2019-04-07 17:14:50 +08:00
2019-04-09 20:48:37 +08:00
def mon_nspawn_shell(arch, cmdline, cwd, seconds=60*30, **kwargs):
assert type(seconds) is int and seconds >= 1
2019-04-07 17:14:50 +08:00
return nspawn_shell(arch, cmdline, cwd=cwd, keepalive=True, KEEPALIVE_TIMEOUT=60,
2019-04-09 20:48:37 +08:00
RUN_CMD_TIMEOUT=seconds, **kwargs)
2019-04-07 17:14:50 +08:00
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):
2019-04-09 16:42:03 +08:00
if self.__short_return and super().__len__() >= 20:
super().pop(0)
super().append(mystring)
2019-04-09 15:43:17 +08:00
if self.__file and type(mystring) is str:
self.__file.write(mystring)
2019-04-09 23:02:48 +08:00
self.__file.flush()
2019-04-09 15:43:17 +08:00
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)
if line is '':
sleep(0.05)
continue
line.replace('\x0f', '\n')
2019-04-07 17:14:50 +08:00
last_read_time = int(time())
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)
2019-04-11 14:55:42 +08:00
if logfile:
logger.debug('run_cmd: logfile written to %s', str(logfile))
else:
logger.debug('run_cmd: %s, ret = %s', cmd, outstr)
2019-04-02 22:03:28 +08:00
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='):
2019-09-06 12:31:46 +08:00
matches = re.findall(r'[()\s\'\"]([\w]+)[()\s\'\"]', line)
2019-04-07 17:14:50 +08:00
if not matches:
raise TypeError('Unexpected PKGBUILD format')
2019-04-09 21:46:50 +08:00
matches = [arch for arch in matches if arch in ARCHS]
2019-04-07 17:14:50 +08:00
return matches
raise TypeError('Unexpected PKGBUILD')
def print_exc_plus():
2019-09-06 13:00:10 +08:00
logger.critical("Exception caught.\nPrinting stack traceback\n" + format_exc_plus())
2019-04-09 15:43:17 +08:00
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
2019-04-09 20:48:37 +08:00
def configure_logger(logger, format='%(asctime)s - %(name)-18s - %(levelname)s - %(message)s',
level=logging.INFO, logfile=None, flevel=logging.DEBUG, rotate_size=None,
2019-09-06 11:45:12 +08:00
enable_notify=False, consolelog=None):
2019-09-05 22:42:08 +08:00
2019-09-06 13:00:10 +08:00
class NotifyHandler(logging.NullHandler):
def handle(self, record):
send(self.formatter.format(record))
2019-04-09 15:43:17 +08:00
2019-04-11 15:02:50 +08:00
logger.setLevel(logging.DEBUG)
2019-09-06 13:00:10 +08:00
formatter = logging.Formatter(fmt=format)
2019-04-09 15:43:17 +08:00
# 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)
2019-09-06 13:00:10 +08:00
fh.setFormatter(formatter)
2019-04-09 15:43:17 +08:00
logger.addHandler(fh)
# create console handler
ch = logging.StreamHandler()
ch.setLevel(level)
2019-09-06 13:00:10 +08:00
ch.setFormatter(formatter)
2019-04-09 15:43:17 +08:00
logger.addHandler(ch)
2019-09-06 13:00:10 +08:00
# for client.printlog
2019-09-06 11:45:12 +08:00
if consolelog:
assert type(consolelog) is str
cfh = logging.FileHandler(consolelog)
cfh.setLevel(level)
2019-09-06 13:00:10 +08:00
cfh.setFormatter(formatter)
2019-09-06 11:45:12 +08:00
logger.addHandler(cfh)
2019-09-06 13:00:10 +08:00
# notify
if enable_notify:
try:
from notify import send
except ModuleNotFoundError:
print('Failed to import notify.send')
else:
nh = NotifyHandler()
nh.setLevel(level)
nh.setFormatter(formatter)
logger.addHandler(nh)