deckard.py 15.2 KB
Newer Older
1
#!/usr/bin/env python3
2
from datetime import datetime
3
import errno
4
import ipaddress
5
import logging
6
import logging.config
Marek Vavruša's avatar
Marek Vavruša committed
7 8 9
import os
import shutil
import socket
10 11
import subprocess
import tempfile
Marek Vavruša's avatar
Marek Vavruša committed
12
import time
13
from typing import Set  # noqa
14

15
import dpkt
Marek Vavruša's avatar
Marek Vavruša committed
16 17
import jinja2

18
from pydnstest import scenario, testserver
19

20

21 22
# path to Deckard files
INSTALLDIR = os.path.dirname(os.path.abspath(__file__))
23 24
# relative to working directory
TRUST_ANCHOR_SUBDIR = 'ta'
25

Marek Vavruša's avatar
Marek Vavruša committed
26

27 28 29 30
class DeckardUnderLoadError(Exception):
    pass


31
class IfaceManager:
32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90
    """
    Network interface allocation manager

    Keeps mapping between 'name', interface number, and IP address.
    """
    def __init__(self, sockfamily):
        """
        Parameters:
            sockfamily Address family used in given test scenatio
                       (a constant from socket module)
        """
        if sockfamily not in {socket.AF_INET, socket.AF_INET6}:
            raise NotImplementedError("address family not supported '%i'" % sockfamily)
        self.sockfamily = sockfamily
        self.free = list(range(40, 10, -1))  # range accepted by libswrap
        self.name2iface = {}

    def allocate(self, name):
        """
        Map name to a free interface number.
        """
        if name in self.name2iface:
            raise ValueError('duplicate interface name %s' % name)
        iface = str(self.free.pop())
        self.name2iface[name] = iface
        return iface

    def getiface(self, name):
        """
        Map name to allocated interface number.

        Returns:
            Interface number as string (so it can be assigned to os.environ)
        """
        return self.name2iface[name]

    def getipaddr(self, name):
        """
        Get default IP address assigned to interface allocated to given name.

        Returns:
            Address from address family specified during IfaceManager init.
        """
        iface = self.getiface(name)
        if self.sockfamily == socket.AF_INET:
            addr_local_pattern = "127.0.0.{}"
        elif self.sockfamily == socket.AF_INET6:
            addr_local_pattern = "fd00::5357:5f{:02X}"
        return addr_local_pattern.format(int(iface))

    def getalladdrs(self):
        """
        Get mapping from all names to all IP addresses.

        Returns:
            {name: IP address}
        """
        return {name: self.getipaddr(name)
                for name in self.name2iface}
Marek Vavruša's avatar
Marek Vavruša committed
91

Marek Vavrusa's avatar
Marek Vavrusa committed
92

Marek Vavruša's avatar
Marek Vavruša committed
93 94
def write_timestamp_file(path, tst):
    time_file = open(path, 'w')
95 96
    time_file.write(datetime.fromtimestamp(tst).strftime('@%Y-%m-%d %H:%M:%S'))
    time_file.flush()
Marek Vavruša's avatar
Marek Vavruša committed
97 98
    time_file.close()

99

100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115
def setup_common_env(ctx):
    """
    Setup environment shared between Deckard and binaries under test.

    Environment for child processes must be based on on.environ as modified
    by this function.

    Returns:
        path to working directory
    """
    # working directory
    if "SOCKET_WRAPPER_DIR" in os.environ:
        tmpdir = os.environ["SOCKET_WRAPPER_DIR"]
        if os.path.lexists(tmpdir):
            raise ValueError('SOCKET_WRAPPER_DIR "%s" must not exist' % tmpdir)
    else:
116
        # uses TMPDIR environment variable (if dir exists)
117 118
        tmpdir = tempfile.mkdtemp(suffix='', prefix='tmpdeckard')

Marek Vavruša's avatar
Marek Vavruša committed
119 120
    # Set up libfaketime
    os.environ["FAKETIME_NO_CACHE"] = "1"
121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179
    os.environ["FAKETIME_TIMESTAMP_FILE"] = '%s/.time' % tmpdir
    # fake initial time
    write_timestamp_file(os.environ["FAKETIME_TIMESTAMP_FILE"],
                         ctx.get('_OVERRIDE_TIMESTAMP', time.time()))

    # Set up socket_wrapper
    os.environ["SOCKET_WRAPPER_DIR"] = tmpdir
    os.environ["SOCKET_WRAPPER_PCAP_FILE"] = '%s/deckard.pcap' % tmpdir

    return tmpdir


def setup_daemon_env(prog_cfg, tmpdir):
    """ Set up test environment and config """
    name = prog_cfg['name']
    log = logging.getLogger('deckard.daemon.%s.setup_env' % name)
    # Set up child process env() to use socket wrapper interface
    child_env = os.environ.copy()
    child_env['SOCKET_WRAPPER_DEFAULT_IFACE'] = prog_cfg['iface']
    prog_cfg['dir'] = os.path.join(tmpdir, name)
    log.debug('directory: %s', prog_cfg['dir'])
    child_env['SOCKET_WRAPPER_PCAP_FILE'] = '%s/pcap' % prog_cfg['dir']

    return child_env


def setup_network(sockfamily, prog_cfgs):
    """Allocate fake interfaces and IP addresses to all entities.

    Returns:
    - SOCKET_WRAPPER_DEFAULT_IFACE will be set in os.environ
    - Dict suitable for usage in Jinja2 templates will be returned
        {
         ROOT_ADDR: <DeckardIP>,
         IPADDRS: {name: <IPaddress>}
        }
    """
    net_config = {}
    # assign interfaces and IP addresses to all involved programs
    ifacemgr = IfaceManager(sockfamily)
    # fake interface for Deckard itself
    deckard_iface = ifacemgr.allocate('deckard')
    os.environ['SOCKET_WRAPPER_DEFAULT_IFACE'] = deckard_iface
    net_config['ROOT_ADDR'] = ifacemgr.getipaddr('deckard')

    for prog_cfg in prog_cfgs['programs']:
        prog_cfg['iface'] = ifacemgr.allocate(prog_cfg['name'])
        prog_cfg['ipaddr'] = ifacemgr.getipaddr(prog_cfg['name'])
    net_config['IPADDRS'] = ifacemgr.getalladdrs()

    return net_config


def _fixme_prebind_hack(sockfamily, childaddr):
    """
    Prebind to sockets to create necessary files

    @TODO: this is probably a workaround for socket_wrapper bug
    """
180 181
    if 'NOPRELOAD' not in os.environ:
        for sock_type in (socket.SOCK_STREAM, socket.SOCK_DGRAM):
182 183
            sock = socket.socket(sockfamily, sock_type)
            sock.setsockopt(sockfamily, socket.SO_REUSEADDR, 1)
184
            sock.bind((childaddr, 53))
185
            if sock_type & socket.SOCK_STREAM:
186
                sock.listen(5)
Marek Vavruša's avatar
Marek Vavruša committed
187

188

189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215
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(l) for l in ta_lines)
    return full_paths


def setup_daemon_files(prog_cfg, template_ctx, ta_files):
216 217 218 219
    name = prog_cfg['name']
    # add program-specific variables
    subst = template_ctx.copy()
    subst['DAEMON_NAME'] = name
Marek Vavruša's avatar
Marek Vavruša committed
220

221 222 223
    subst['WORKING_DIR'] = prog_cfg['dir']
    os.mkdir(prog_cfg['dir'])
    subst['SELF_ADDR'] = prog_cfg['ipaddr']
224

225 226 227 228
    # daemons might write to TA files so every daemon gets its own copy
    subst['TRUST_ANCHOR_FILES'] = create_trust_anchor_files(
        ta_files, prog_cfg['dir'])

229
    # generate configuration files
230 231
    j2template_loader = jinja2.FileSystemLoader(searchpath=os.getcwd())
    print(os.path.abspath(os.getcwd()))
232
    j2template_env = jinja2.Environment(loader=j2template_loader)
233
    logging.getLogger('deckard.daemon.%s.template' % name).debug(subst)
234

235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253
    assert len(prog_cfg['templates']) == len(prog_cfg['configs'])
    for template_name, config_name in zip(prog_cfg['templates'], prog_cfg['configs']):
        j2template = j2template_env.get_template(template_name)
        cfg_rendered = j2template.render(subst)
        with open(os.path.join(prog_cfg['dir'], config_name), 'w') as output:
            output.write(cfg_rendered)

    _fixme_prebind_hack(template_ctx['_SOCKET_FAMILY'], subst['SELF_ADDR'])


def run_daemon(cfg, environ):
    """Start binary and return its process object"""
    name = cfg['name']
    proc = None
    cfg['log'] = os.path.join(cfg['dir'], 'server.log')
    daemon_log_file = open(cfg['log'], 'w')
    cfg['args'] = args = [cfg['binary']] + cfg['additional']
    logging.getLogger('deckard.daemon.%s.env' % name).debug('%s', environ)
    logging.getLogger('deckard.daemon.%s.argv' % name).debug('%s', args)
254
    try:
255
        proc = subprocess.Popen(args, stdout=daemon_log_file, stderr=subprocess.STDOUT,
256
                                cwd=cfg['dir'], env=environ, start_new_session=True)
257 258 259 260 261 262 263 264 265 266
    except subprocess.CalledProcessError:
        logger = logging.getLogger('deckard.daemon_log.%s' % name)
        logger.exception("Can't start '%s'", args)
        raise
    return proc


def conncheck_daemon(process, cfg, sockfamily):
    """Wait until the server accepts TCP clients"""
    sock = socket.socket(sockfamily, socket.SOCK_STREAM)
267
    tstart = datetime.now()
Marek Vavruša's avatar
Marek Vavruša committed
268
    while True:
269
        time.sleep(0.1)
270 271 272 273
        if (datetime.now() - tstart).total_seconds() > 5:
            raise RuntimeError("Server took too long to respond")
        # Check if the process is running
        if process.poll() is not None:
274 275 276 277 278
            msg = 'process died "%s", logs in "%s"' % (cfg['name'], cfg['dir'])
            logger = logging.getLogger('deckard.daemon_log.%s' % cfg['name'])
            logger.critical(msg)
            logger.error(open(cfg['log']).read())
            raise subprocess.CalledProcessError(process.returncode, cfg['args'], msg)
Marek Vavruša's avatar
Marek Vavruša committed
279
        try:
280
            sock.connect((cfg['ipaddr'], 53))
281
        except socket.error:
282
            continue
Marek Vavruša's avatar
Marek Vavruša committed
283
        break
284 285
    sock.close()

286

287
def process_file(path, qmin, prog_cfgs):
288
    """Parse scenario from a file object and create workdir."""
289
    # Parse scenario
290
    case, cfg_text = scenario.parse_file(os.path.realpath(path))
291
    cfg_ctx, ta_files = scenario.parse_config(cfg_text, qmin, INSTALLDIR)
292 293 294
    template_ctx = setup_network(cfg_ctx['_SOCKET_FAMILY'], prog_cfgs)
    # merge variables from scenario with generated network variables (scenario has priority)
    template_ctx.update(cfg_ctx)
295 296 297
    # Deckard will communicate with first program
    prog_under_test = prog_cfgs['programs'][0]['name']
    prog_under_test_ip = template_ctx['IPADDRS'][prog_under_test]
298

299 300
    # get working directory and environment variables
    tmpdir = setup_common_env(cfg_ctx)
301
    shutil.copy2(path, os.path.join(tmpdir))
302
    try:
303
        daemons = setup_daemons(tmpdir, prog_cfgs, template_ctx, ta_files)
304 305 306 307 308
        run_testcase(daemons,
                     case,
                     template_ctx['ROOT_ADDR'],
                     template_ctx['_SOCKET_FAMILY'],
                     prog_under_test_ip)
309 310 311 312 313
        if prog_cfgs.get('noclean'):
            logging.getLogger('deckard.hint').info(
                'test working directory %s', tmpdir)
        else:
            shutil.rmtree(tmpdir)
Tomas Krizek's avatar
Tomas Krizek committed
314
    except Exception:
315
        logging.getLogger('deckard.hint').error(
316 317 318 319
            'test failed, inspect working directory %s', tmpdir)
        raise


320
def setup_daemons(tmpdir, prog_cfgs, template_ctx, ta_files):
321
    """Configure daemons and run the test"""
322 323 324 325
    # Setup daemon environment
    daemons = []
    for prog_cfg in prog_cfgs['programs']:
        daemon_env = setup_daemon_env(prog_cfg, tmpdir)
326
        setup_daemon_files(prog_cfg, template_ctx, ta_files)
327 328
        daemon_proc = run_daemon(prog_cfg, daemon_env)
        daemons.append({'proc': daemon_proc, 'cfg': prog_cfg})
329 330
        try:
            conncheck_daemon(daemon_proc, prog_cfg, template_ctx['_SOCKET_FAMILY'])
Tomas Krizek's avatar
Tomas Krizek committed
331
        except:  # noqa  -- bare except might be valid here?
332 333
            daemon_proc.terminate()
            raise
334
    return daemons
335

336

337
def check_for_icmp():
Štěpán Balážik's avatar
Štěpán Balážik committed
338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354
    """ Checks Deckards's PCAP for ICMP packets """
    # Deckard's responses to resolvers might be delayed due to load which
    # leads the resolver to close the port and to the test failing in the
    # end. We partially detect these by checking the PCAP for ICMP packets.
    path = os.environ["SOCKET_WRAPPER_PCAP_FILE"]
    udp_seen = False
    with open(path, "rb") as f:
        pcap = dpkt.pcap.Reader(f)
        for _, packet in pcap:
            try:
                ip = dpkt.ip.IP(packet)
            except dpkt.dpkt.UnpackError:
                ip = dpkt.ip6.IP6(packet)
            if isinstance(ip.data, dpkt.udp.UDP):
                udp_seen = True

            if udp_seen:
355
                if isinstance(ip.data, (dpkt.icmp.ICMP, dpkt.icmp6.ICMP6)):
Štěpán Balážik's avatar
Štěpán Balážik committed
356 357 358 359
                    raise DeckardUnderLoadError("Deckard is under load. "
                                                "Other errors might be false negatives. "
                                                "Consider retrying the job later.")
        return False
360 361


362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399
def check_for_reply_steps(case: scenario.Scenario) -> bool:
    return any(s.type == "REPLY" for s in case.steps)


def check_for_unknown_servers(case: scenario.Scenario, daemon: dict) -> None:
    """ Checks Deckards's PCAP for packets going to servers not present in scenario """
    path = os.path.join(daemon["cfg"]["dir"], "pcap")
    asked_servers = set()
    with open(path, "rb") as f:
        pcap = dpkt.pcap.Reader(f)
        for _, packet in pcap:
            try:
                ip = dpkt.ip.IP(packet)
            except dpkt.dpkt.UnpackError:
                ip = dpkt.ip6.IP6(packet)
            # pylint: disable=no-member
            dest = ipaddress.ip_address(int.from_bytes(ip.dst, byteorder="big"))
            # pylint: enable=no-member

            # Socket wrapper asigns (random) link local addresses to the binary under test
            # and Deckard itself. We have to filter them out of the pcap.
            if dest.is_global:
                asked_servers.add(dest)

    scenario_ips = set()  # type: Set[str]
    for r in case.ranges:
        scenario_ips |= r.addresses

    scenario_servers = {ipaddress.ip_address(ip) for ip in scenario_ips}

    servers_not_in_scenario = asked_servers - scenario_servers

    if servers_not_in_scenario:
        if not check_for_reply_steps(case):
            raise RuntimeError("Binary in test asked an IP address not present in scenario %s"
                               % servers_not_in_scenario)


400 401 402
def run_testcase(daemons, case, root_addr, addr_family, prog_under_test_ip):
    """Run actual test and raise exception if the test failed"""
    server = testserver.TestServer(case, root_addr, addr_family)
403 404
    server.start()

Marek Vavruša's avatar
Marek Vavruša committed
405
    try:
406
        server.play(prog_under_test_ip)
407 408 409
    except ValueError as e:
        if not check_for_icmp():
            raise e
Marek Vavruša's avatar
Marek Vavruša committed
410 411
    finally:
        server.stop()
412 413 414 415 416

        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)

417 418 419 420 421 422 423
        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())
424
            ignore_exit = daemon["cfg"].get('ignore_exit_code', False)
425 426 427
            if daemon['proc'].returncode != 0 and not ignore_exit:
                raise ValueError('process %s terminated with return code %s'
                                 % (daemon['cfg']['name'], daemon['proc'].returncode))
428 429
            check_for_unknown_servers(case, daemon)

Marek Vavruša's avatar
Marek Vavruša committed
430
    # Do not clear files if the server crashed (for analysis)
431
    if server.undefined_answers > 0:
432 433
        if not check_for_icmp():
            raise ValueError('the scenario does not define all necessary answers (see error log)')