#!/usr/bin/env python3 import errno import logging import logging.config import os import shlex import shutil import socket import subprocess import time from datetime import datetime from typing import Set # noqa import jinja2 from pydnstest import scenario, testserver # path to Deckard files INSTALLDIR = os.path.dirname(os.path.abspath(__file__)) # relative to working directory TRUST_ANCHOR_SUBDIR = 'ta' class DeckardUnderLoadError(Exception): pass def setup_internal_addresses(context): context["DECKARD_IP"] = context["if_manager"].assign_internal_address(context["_SOCKET_FAMILY"]) for program in context["programs"]: program["address"] = context["if_manager"].assign_internal_address( context["_SOCKET_FAMILY"]) def write_timestamp_file(path, tst): with open(path, 'w') as time_file: time_file.write(datetime.fromtimestamp(tst).strftime('@%Y-%m-%d %H:%M:%S')) def setup_faketime(context): """ Setup environment shared between Deckard and binaries under test. Environment for child processes must be based on on.environ as modified by this function. """ # Set up libfaketime os.environ["FAKETIME_NO_CACHE"] = "1" os.environ["FAKETIME_TIMESTAMP_FILE"] = os.path.join(context["tmpdir"], ".time") os.unsetenv("FAKETIME") write_timestamp_file(os.environ["FAKETIME_TIMESTAMP_FILE"], context.get('_OVERRIDE_TIMESTAMP', time.time())) def setup_daemon_environment(program_config, context): program_config["WORKING_DIR"] = os.path.join(context["tmpdir"], program_config["name"]) os.mkdir(program_config['WORKING_DIR']) program_config["DAEMON_NAME"] = program_config["name"] program_config['SELF_ADDR'] = program_config['address'] program_config['TRUST_ANCHOR_FILES'] = create_trust_anchor_files( context["TRUST_ANCHOR_FILES"], program_config['WORKING_DIR']) def create_trust_anchor_files(ta_files, work_dir): """ Write trust anchor files in specified working directory. Params: ta_files Dict {domain name: [TA lines]} Returns: List of absolute filesystem paths to TA files. """ full_paths = [] for domain, ta_lines in ta_files.items(): file_name = u'{}.key'.format(domain) full_path = os.path.realpath( os.path.join(work_dir, TRUST_ANCHOR_SUBDIR, file_name)) full_paths.append(full_path) dir_path = os.path.dirname(full_path) try: os.makedirs(dir_path) except OSError as ex: if ex.errno != errno.EEXIST: raise with open(full_path, "w") as ta_file: ta_file.writelines('{0}\n'.format(line) for line in ta_lines) return full_paths def generate_from_templates(program_config, context): """Generate configuration for the program""" template_ctx = context.copy() template_ctx.update(program_config) # public mapping program name -> program vars template_ctx['PROGRAMS'] = {} for cfg in template_ctx['programs']: template_ctx['PROGRAMS'][cfg['name']] = cfg j2template_loader = jinja2.FileSystemLoader(searchpath=os.getcwd()) j2template_env = jinja2.Environment(loader=j2template_loader) for template_name, config_name in zip(template_ctx['templates'], template_ctx['configs']): j2template = j2template_env.get_template(template_name) cfg_rendered = j2template.render(template_ctx) with open(os.path.join(template_ctx['WORKING_DIR'], config_name), 'w') as output: output.write(cfg_rendered) def run_daemon(program_config): """Start binary and return its process object""" name = program_config['DAEMON_NAME'] proc = None program_config['log'] = os.path.join(program_config["WORKING_DIR"], 'server.log') program_config['args'] = ( shlex.split(os.environ.get('DECKARD_WRAPPER', '')) + [program_config['binary']] + program_config['additional'] ) logging.getLogger('deckard.daemon.%s.argv' % name).debug('%s', program_config['args']) with open(program_config['log'], 'w') as daemon_log_file: try: # pylint: disable=consider-using-with proc = subprocess.Popen(program_config['args'], stdout=daemon_log_file, stderr=subprocess.STDOUT, cwd=program_config['WORKING_DIR']) except subprocess.CalledProcessError: logger = logging.getLogger('deckard.daemon_log.%s' % name) logger.exception("Can't start '%s'", program_config['args']) raise return proc def log_fatal_daemon_error(cfg, msg): logger = logging.getLogger('deckard.daemon_log.%s' % cfg['name']) logger.critical(msg) logger.critical('logs are in "%s"', cfg['WORKING_DIR']) with open(cfg['log']) as logfile: logger.error('daemon log follows:') logger.error(logfile.read()) def conncheck_daemon(process, cfg, sockfamily): """Wait until the server accepts TCP clients""" sock = socket.socket(sockfamily, socket.SOCK_STREAM) deadline = time.monotonic() + 5 with sock: while True: # Check if the process is running if process.poll() is not None: msg = 'process died, exit code %s' % process.poll() log_fatal_daemon_error(cfg, msg) raise subprocess.CalledProcessError(process.returncode, cfg['args'], msg) try: sock.connect((cfg['address'], 53)) return # success except socket.error as ex: if time.monotonic() > deadline: msg = 'server does not accept connections on TCP port 53' log_fatal_daemon_error(cfg, msg) raise DeckardUnderLoadError(msg) from ex time.sleep(0.1) def setup_daemons(context): """Configure daemons and start them""" # Setup daemon environment daemons = [] for program_config in context['programs']: setup_daemon_environment(program_config, context) generate_from_templates(program_config, context) daemon_proc = run_daemon(program_config) daemons.append({'proc': daemon_proc, 'cfg': program_config}) if program_config.get('conncheck', True): try: conncheck_daemon(daemon_proc, program_config, context['_SOCKET_FAMILY']) except: # noqa -- bare except might be valid here? daemon_proc.terminate() raise return daemons def check_for_reply_steps(case: scenario.Scenario) -> bool: return any(s.type == "REPLY" for s in case.steps) def run_testcase(case, daemons, context, prog_under_test_ip): """Run actual test and raise exception if the test failed""" server = testserver.TestServer(case, context["_SOCKET_FAMILY"], context["DECKARD_IP"], context["if_manager"]) server.start() try: server.play(prog_under_test_ip) finally: server.stop() if check_for_reply_steps(case): logging.warning("%s has REPLY steps in it. These are known to fail randomly. " "Errors might be false positives.", case.file) for daemon in daemons: daemon['proc'].terminate() daemon['proc'].wait() daemon_logger_log = logging.getLogger('deckard.daemon_log.%s' % daemon['cfg']['name']) with open(daemon['cfg']['log']) as logf: for line in logf: daemon_logger_log.debug(line.strip()) ignore_exit = daemon["cfg"].get('ignore_exit_code', False) if daemon['proc'].returncode != 0 and not ignore_exit: raise ValueError('process %s terminated with return code %s' % (daemon['cfg']['name'], daemon['proc'].returncode)) if server.undefined_answers > 0: raise ValueError('the scenario does not define all necessary answers (see error log)') def process_file(path, qmin, config): """Parse scenario from a file object and create workdir.""" # Preserve original configuration context = config.copy() # Parse scenario case, case_config_text = scenario.parse_file(os.path.realpath(path)) case_config = scenario.parse_config(case_config_text, qmin, INSTALLDIR) # Merge global and scenario configs context.update(case_config) # Asign addresses to the programs and Deckard itself setup_internal_addresses(context) # Deckard will communicate with first program prog_under_test_ip = context['programs'][0]['address'] setup_faketime(context) # Copy the scenario to tmpdir for future reference shutil.copy2(path, os.path.join(context["tmpdir"])) try: daemons = setup_daemons(context) run_testcase(case, daemons, context, prog_under_test_ip) except Exception: logging.getLogger('deckard.hint').error( 'test failed, inspect working directory %s', context["tmpdir"]) raise