chiark / gitweb /
wip on debugging with dovecot - new --unbuilt-tree feature
[autopkgtest.git] / runner / adt-run
index 38290b7a42414d36469561283e62e38a4f5f6cd1..b6a37fd5edc138a6a918dffd1046387046eb6a7b 100755 (executable)
@@ -3,7 +3,7 @@
 # adt-run is part of autopkgtest
 # autopkgtest is a tool for testing Debian binary packages
 #
-# autopkgtest is Copyright (C) 2006 Canonical Ltd.
+# autopkgtest is Copyright (C) 2006-2007 Canonical Ltd.
 #
 # This program is free software; you can redistribute it and/or modify
 # it under the terms of the GNU General Public License as published by
@@ -47,22 +47,108 @@ testbed = None             # Testbed
 errorcode = 0          # exit status that we are going to use
 binaries = None                # Binaries (.debs we have registered)
 
+#---------- output handling
+#
+#  There are at least the following kinds of output:
+#
+#   1. stderr output which consists of
+#   1a. our errors
+#   1b. stuff printed to stderr by the virtualisation server
+#   1c. stuff printed to stderr by our short-lived subprocesseses
+#           which we don't expect to fail
+#
+#   2. trace information, which consists of
+#   2a. our trace information from calls to debug()
+#   2b. progress information and stderr output from
+#        general scripts we run on the host
+#   2c. progress information and stderr output from things
+#        we run on the testbed including builds
+#   2d. stderr and stdout output from actual tests
+#
+#   xxxx
+#   3. actual test results (printed to our stdout)
+#
+# Cloning of 1a and 2a, where necessary, is done by us writing
+# the data twice.  Cloning of 1[bc] and 2[bc], where necessary,
+# is done by forking off a copy of ourselves to do plumbing,
+# which copy we wait for at the appropriate point.
+
+trace_stream = None
+
+def pstderr(m):
+       print >>sys.stderr, m
+       if trace_stream is not None: print >>trace_stream, m
+
+def debug(m):
+       if not opts.debug and trace_stream is None: return
+       for l in m.rstrip('\n').split('\n'):
+               s = 'atd-run: debug: ' + l
+               if opts.debug: print >>sys.stderr, s
+               if trace_stream is not None: print >>trace_stream, s
+
+def debug_file(hp):
+       def do_copy(stream, what):
+               rc = subprocess.call(['cat',hp], stdout=stream)
+               if rc: bomb('cat failed copying data from %s'
+                           ' to %s, exit code %d' % (hp, what, rc))
+       if opts.debug: do_copy(sys.stderr, 'stderr')
+       if trace_stream is not None: do_copy(trace_stream, 'trace log')
+
+class Errplumb:
+ def __init__(ep, critical=False):
+       to_stderr = critical or opts.debug
+       count = to_stderr + (trace_stream is not None)
+       if count == 0:
+               ep.stream = open('/dev/null','w')
+               ep._sp = None
+       elif count == 1:
+               if to_stderr: ep.stream = sys.stderr
+               else: ep.stream = trace_stream
+               ep._sp = None
+       else:
+               ep._sp = subprocess.Popen(['tee','/dev/stderr'],
+                       stdin=subprocess.PIPE, stdout=trace_stream,
+                       close_fds=True)
+               ep.stream = ep._sp.stdin
+ def wait(ep):
+       if ep._sp is None: return
+       ep._sp.stdin.close()
+       rc = ep._sp.wait()
+       if rc: bomb('stderr plumbing tee(1) failed, exit code %d' % rc)
+       ep._sp = None
+
+def subprocess_cooked(cmdl, critical=False, dbg=None, **kwargs):
+       if dbg is not None:
+               if isinstance(dbg,tuple): (what,script) = dbg
+               else: (what,script) = (dbg,None)
+               debug_subprocess(what, cmdl, script=script)
+       ep = Errplumb(critical)
+       running = subprocess.Popen(cmdl, stderr=ep.stream, **kwargs)
+       output = running.communicate()[0]
+       rc = running.wait()
+       ep.wait()
+       return (rc, output)
+
+def preport(m):
+       print m
+       if trace_stream is not None: print >>trace_stream, m
+
+def report(tname, result):
+       preport('%-20s %s' % (tname, result))
+
 #---------- errors we define
 
 class Quit:
        def __init__(q,ec,m): q.ec = ec; q.m = m
 
-def bomb(m, se=''):
-       print >>sys.stderr, se
+def bomb(m):
        raise Quit(20, "unexpected error: %s" % m)
 
-def badpkg(m, se=''):
-       print >>sys.stderr, se
-       print 'blame: ', ' '.join(testbed.blamed)
+def badpkg(m):
+       preport('blame: ' + ' '.join(testbed.blamed))
+       preport('badpkg: ' + m)
        raise Quit(12, "erroneous package: %s" % m)
 
-def report(tname, result): print '%-20s %s' % (tname, result)
-
 class Unsupported:
  def __init__(u, lno, m):
        if lno >= 0: u.m = '%s (control line %d)' % (m, lno)
@@ -72,11 +158,7 @@ class Unsupported:
        errorcode != 2
        report(tname, 'SKIP %s' % u.m)
 
-def debug(m):
-       global opts
-       if not opts.debug: return
-       for l in m.rstrip('\n').split('\n'):
-               print >>sys.stderr, 'atd-run: debug:', l
+#---------- convenience function
 
 def mkdir_okexist(pathname, mode=02755):
        try:
@@ -123,6 +205,8 @@ class AutoFile:
        p.spec = None
        p.dir = ''
 
+ def __repr__(p):
+       return "<AF@%s>" % p.__str__()
  def __str__(p):
        def ptbp(tbp):
                if p.path[tbp] is None: return '-'+p.dir
@@ -164,12 +248,12 @@ class AutoFile:
                        mkdir_okexist(p.path[tbp])
                else:
                        cmdl = ['sh','-ec',
-                               'test -d "$1" || mkdir "$1"',
+                               'test -d "$1" || mkdir -p "$1"',
                                'x', p.path[tbp]]
                        tf_what = urllib.quote(p.what).replace('/','%2F')
-                       (rc,se) = testbed.execute('mkdir-'+tf_what, cmdl)
+                       rc = testbed.execute('mkdir-'+tf_what, cmdl)
                        if rc: bomb('failed to create directory %s' %
-                               p.path[tbp], se)
+                               p.path[tbp])
 
        p.file[tbp] = p.path[tbp]
        return p.path[tbp]
@@ -204,7 +288,7 @@ class AutoFile:
        for tbp in [False,True]:
         for pf in [p.path, p.file]:
                if pf[tbp] is None: continue
-               if not pf[tbp]: bomb('empty path specified for '+p.what)
+               if not pf[tbp]: bomb('empty path specified for %s' % p.what)
                if p.dir and pf[tbp].endswith('/'):
                        pf[tbp] = pf[tbp].rstrip('/')
                        if not pf[tbp]: pf[tbp] = '/'
@@ -294,6 +378,8 @@ class Action:
        a.af = af
        a.ah = arghandling
        a.what = what
+ def __repr__(a):
+       return "<Action %s %s %s>" % (a.kind, a.what, `a.af`)
 
 def parse_args():
        global opts
@@ -317,7 +403,6 @@ def parse_args():
        # actions (ie, test sets to run, sources to build, binaries to use):
 
        def cb_action(op,optstr,value,parser, long,kindpath,is_act):
-               print >>sys.stderr, "cb_action", is_act
                parser.largs.append((value,kindpath))
                n_non_actions += not(is_act)
 
@@ -326,7 +411,10 @@ def parse_args():
                        nargs=1, type='string',
                        callback_args=(long,kindpath,is_act), help=help)
 
-       pa_action('build-tree',         'TREE', '@/',
+       pa_action('built-tree',         'TREE', '@/',
+               help='run tests from build tree TREE')
+
+       pa_action('unbuilt-tree',       'TREE', '@//',
                help='run tests from build tree TREE')
 
        pa_action('source',             'DSC', '@.dsc',
@@ -421,12 +509,15 @@ def parse_args():
        pa('','--tmp-dir',              type='string', dest='tmpdir',
                help='write temporary files to TMPDIR, emptying it'
                     ' beforehand and leaving it behind at the end')
+       pa('','--log-file',             type='string', dest='logfile',
+               help='write the log LOGFILE, emptying it beforehand,'
+                    ' instead of using OUTPUT-DIR/log or TMPDIR/log')
 
        pa('','--user',                 type='string', dest='user',
                help='run tests as USER (needs root on testbed)')
        pa('','--gain-root',            type='string', dest='gainroot',
                help='prefix debian/rules binary with GAINROOT')
-       pa('-d', '--debug', action='store_true', dest='debug');
+       pa('-q', '--quiet', action='store_false', dest='debug', default=True);
        pa('','--gnupg-home',           type='string', dest='gnupghome',
                default='~/.autopkgtest/gpg',
                help='use GNUPGHOME rather than ~/.autopkgtest (for'
@@ -477,6 +568,9 @@ def parse_args():
                if type(kindpath) is tuple:             kind = kindpath[0]
                elif kindpath.endswith('.deb'):         kind = 'deb'
                elif kindpath.endswith('.dsc'):         kind = 'dsc'
+               elif kindpath.endswith('//'):
+                       kind = 'ubtree'
+                       constructor = InputDir
                elif kindpath.endswith('/'):
                        kind = 'tree'
                        constructor = InputDir
@@ -491,8 +585,8 @@ def parse_args():
                af = constructor(what+fwhatx, pathstr, arghandling['tb'])
                opts.actions.append(Action(kind, af, arghandling, what))
 
-def finalise_options():
-       global opts, tb, tmpdir
+def setup_trace():
+       global trace_stream, tmpdir
 
        if opts.tmpdir is not None:
                rmtree('tmpdir(specified)',opts.tmpdir)
@@ -502,6 +596,19 @@ def finalise_options():
                assert(tmpdir is None)
                tmpdir = tempfile.mkdtemp()
 
+       if opts.logfile is None:
+               if opts.output_dir is not None and opts.output_dir.spec_tbp:
+                       opts.logfile = opts.output_dir.spec + '/log'
+               elif opts.tmpdir is not None:
+                       opts.logfile = opts.tmpdir + '/log'
+       if opts.logfile is not None:
+               trace_stream = open(opts.logfile, 'w', 0)
+
+       debug('#options: '+`opts`)
+
+def finalise_options():
+       global opts, tb
+
        if opts.user is None and 'root-on-testbed' not in testbed.caps:
                opts.user = ''
 
@@ -519,10 +626,10 @@ def finalise_options():
 
        if opts.user:
                if 'root-on-testbed' not in testbed.caps:
-                       print >>sys.stderr, ("warning: virtualisation"
+                       pstderr("warning: virtualisation"
                                " system does not offer root on testbed,"
                                " but --user option specified: failure likely")
-               opts.user_wrap = lambda x: 'su %s -c "%s"' % (opts.user, x)
+               opts.user_wrap = lambda x: "su %s -c '%s'" % (opts.user, x)
        else:
                opts.user_wrap = lambda x: x
 
@@ -551,15 +658,18 @@ class Testbed:
        tb.scratch = None
        tb.modified = False
        tb.blamed = []
+       tb._ephemeral = []
        tb._debug('init')
+       tb._need_reset_apt = False
  def _debug(tb, m):
        debug('** '+m)
  def start(tb):
        tb._debug('start')
        p = subprocess.PIPE
        debug_subprocess('vserver', opts.vserver)
+       tb._errplumb = Errplumb(True)
        tb.sp = subprocess.Popen(opts.vserver,
-               stdin=p, stdout=p, stderr=None)
+               stdin=p, stdout=p, stderr=tb._errplumb.stream)
        tb.expect('ok')
        tb.caps = tb.commandr('capabilities')
  def stop(tb):
@@ -574,25 +684,60 @@ class Testbed:
                ec = tb.sp.wait()
        if ec:
                tb.bomb('testbed gave exit status %d after quit' % ec)
+       tb._errplumb.wait()
  def open(tb):
        tb._debug('open, scratch=%s' % tb.scratch)
        if tb.scratch is not None: return
        pl = tb.commandr('open')
        tb.scratch = InputDir('tb-scratch', pl[0], True)
+       tb.deps_processed = []
+ def mungeing_apt(tb):
+       if not 'revert' in tb.caps:
+               tb._need_reset_apt = True
+ def reset_apt(tb):
+       if not tb._need_reset_apt: return
+       what = 'aptget-update-reset'
+       cmdl = ['apt-get','-qy','update']
+       rc = tb.execute(what, cmdl)
+       if rc:
+               pstderr("\n" "warning: failed to restore"
+                       " testbed apt cache, exit code %d" % rc)
+       tb._need_reset_apt = False
  def close(tb):
        tb._debug('close, scratch=%s' % tb.scratch)
        if tb.scratch is None: return
        tb.scratch = None
        if tb.sp is None: return
        tb.command('close')
- def prepare(tb):
-       tb._debug('prepare, modified=%s' % tb.modified)
-       if tb.modified and 'reset' in tb.caps:
+ def prepare(tb, deps_new):
+       tb._debug('prepare, modified=%s, deps_processed=%s, deps_new=%s' %
+               (tb.modified, tb.deps_processed, deps_new))
+       if 'revert' in tb.caps and (tb.modified or
+           [d for d in tb.deps_processed if d not in deps_new]):
                tb._debug('reset **')
-               tb.command('reset')
+               tb.command('revert')
                tb.blamed = []
-       tb.modified = False
+               for af in tb._ephemeral: af.invalidate(True)
        binaries.publish()
+       tb.modified = False
+       tb._install_deps(deps_new)
+ def register_ephemeral(tb, af):
+       if not getattr(af,'spec_tbp',False): tb._ephemeral.append(af)
+ def _install_deps(tb, deps_new):
+       tb._debug(' installing dependencies '+`deps_new`)
+       tb.deps_processed = deps_new
+       if not deps_new: return
+       dstr = ', '.join(deps_new)
+       script = binaries.apt_pkg_gdebi_script(
+               dstr, [[
+               'from GDebi.DebPackage import DebPackage',
+               'd = DebPackage(cache)',
+               'res = d.satisfyDependsStr(arg)',
+               ]])
+       cmdl = ['python','-c',script]
+       what = 'install-deps'
+       rc = testbed.execute(what, cmdl, script=script)
+       if rc: badpkg('dependency install failed, exit code %d' % rc)
  def needs_reset(tb):
        tb._debug('needs_reset, previously=%s' % tb.modified)
        tb.modified = True
@@ -605,8 +750,8 @@ class Testbed:
                tb.sp.stdout.close()
                tb.sp.stdin.close()
                ec = tb.sp.wait()
-               if ec: print >>sys.stderr, ('adt-run: testbed failing,'
-                       ' exit status %d' % ec)
+               if ec: pstderr('adt-run: testbed failing,'
+                               ' exit status %d' % ec)
        tb.sp = None
        raise Quit(16, 'testbed failed: %s' % m)
  def send(tb, string):
@@ -656,24 +801,48 @@ class Testbed:
  def commandr1(tb, cmd, args=()):
        rl = tb.commandr(cmd, args, 1)
        return rl[0]
- def execute(tb, what, cmdargs,
+ def execute(tb, what, cmdl,
                si='/dev/null', so='/dev/null', se=None, cwd=None,
-               dump_fd=None):
+               script=False):
+       # Options for script:
+       #   False - do not call debug_subprocess, no synch. reporting required
+       #   None or string - call debug_subprocess with that value,
+       #                       plumb stderr through synchronously if possible
+       # Options for se:
+       #   None - usual Errplumb (output is of kind 2c)
+       #   string - path on testbed (output is of kind 2d)
+
+       if script is not False: debug_subprocess(what, cmdl, script=script)
        if cwd is None: cwd = tb.scratch.write(True)
-       se_use = se
-       if se_use is None:
-               se_af = TemporaryFile('xerr-'+what)
-               se_use = se_af.write(True)
+
+       xdump = None
+       if se is None:
+               ep = Errplumb()
+               se_catch = TemporaryFile(what+'-xerr')
+               se_use = se_catch.write(True)
+               if opts.debug: xdump = 'debug=2-2'
+               elif trace_stream is not None:
+                       xdump = 'debug=2-%d' % trace_stream.fileno()
+       else:
+               ep = None
+               se_catch = None
+               se_use = se
+
        cmdl = [None,
-               ','.join(map(urllib.quote, cmdargs)),
+               ','.join(map(urllib.quote, cmdl)),
                si, so, se_use, cwd]
-       if dump_fd is not None: cmdl += ['debug=%d-%d' % (dump_fd,2)]
+       if xdump is not None and 'execute-debug' in tb.caps: cmdl += [xdump]
        rc = tb.commandr1('execute', cmdl)
        try: rc = int(rc)
        except ValueError: bomb("execute for %s gave invalid response `%s'"
                                        % (what,rc))
-       if se is not None: return rc
-       return (rc, file(se_af.read()).read())
+
+       if se_catch is not None:
+               debug_file(se_catch.read())
+       if ep is not None:
+               ep.wait()
+
+       return rc
 
 #---------- representation of test control files: Field*, Test, etc.
 
@@ -709,29 +878,46 @@ class Restriction_rw_build_tree(Restriction): pass
 class Restriction_rw_tests_tree(Restriction): pass
 class Restriction_breaks_testbed(Restriction):
  def __init__(r, rname, base):
-       if 'reset' not in testbed.caps:
+       if 'revert' not in testbed.caps:
+               raise Unsupported(f.lno,
+                       'Test breaks testbed but testbed cannot revert')
+class Restriction_needs_root(Restriction):
+ def __init__(r, rname, base):
+       if 'root-on-testbed' not in testbed.caps:
                raise Unsupported(f.lno,
-                       'Test breaks testbed but testbed cannot reset')
+                       'Test needs root on testbed which is not available')
 
 class Field_Restrictions(FieldBase):
  def parse(f):
        for wle in f.words():
                (lno, rname) = wle
-               rname = rname.replace('-','_')
-               try: rclass = globals()['Restriction_'+rname]
+               nrname = rname.replace('-','_')
+               try: rclass = globals()['Restriction_'+nrname]
                except KeyError: raise Unsupported(lno,
                        'unknown restriction %s' % rname)
-               r = rclass(rname, f.base)
+               r = rclass(nrname, f.base)
                f.base['restrictions'].append(r)
 
 class Field_Tests(FieldIgnore): pass
 
+class Field_Depends(FieldBase):
+ def parse(f):
+       print >>sys.stderr, "Field_Depends:", `f.stz`, `f.base`, `f.tnames`, `f.vl`
+       dl = map(lambda x: x.strip(),
+               flatten(map(lambda (lno, v): v.split(','), f.vl)))
+       re = regexp.compile('[^-.+:~0-9a-z()<>=*]')
+       for d in dl:
+               if re.search(d):
+                       badpkg("Test Depends field contains dependency"
+                              " `%s' with invalid characters" % d)
+       f.base['depends'] = dl
+
 class Field_Tests_directory(FieldBase):
  def parse(f):
        td = atmostone(f)
        if td.startswith('/'): raise Unspported(f.lno,
                'Tests-Directory may not be absolute')
-       base['testsdir'] = td
+       f.base['testsdir'] = td
 
 def run_tests(stanzas, tree):
        global errorcode, testbed
@@ -741,28 +927,48 @@ def run_tests(stanzas, tree):
                        report('*', 'SKIP no tests in this package')
                        errorcode |= 8
                for t in tests:
-                       testbed.prepare()
+                       t.prepare()
                        t.run(tree)
                        if 'breaks-testbed' in t.restrictions:
                                testbed.needs_reset()
                testbed.needs_reset()
 
 class Test:
- def __init__(t, tname, base, act_what):
+ def __init__(t, tname, base, act):
        if '/' in tname: raise Unsupported(base[' lno'],
                'test name may not contain / character')
        for k in base: setattr(t,k,base[k])
        t.tname = tname
-       t.what = act_what+'t-'+tname
+       t.act = act
+       t.what = act.what+'t-'+tname
        if len(base['testsdir']): t.path = base['testsdir'] + '/' + tname
        else: t.path = tname
+       t._debug('constructed; path=%s' % t.path)
+       t._debug(' .depends=%s' % t.depends)
+ def _debug(t, m):
+       debug('& %s: %s' % (t.what, m))
  def report(t, m):
        report(t.what, m)
  def reportfail(t, m):
        global errorcode
        errorcode |= 4
        report(t.what, 'FAIL ' + m)
+ def prepare(t):
+       t._debug('preparing')
+       dn = []
+       for d in t.depends:
+               t._debug(' processing dependency '+d)
+               if not '_' in d:
+                       t._debug('  literal dependency '+d)
+                       dn.append(d)
+               else:
+                       for (pkg,bin) in t.act.binaries:
+                               d = d.replace('_',pkg)
+                               t._debug('  synthesised dependency '+d)
+                               dn.append(d)
+       testbed.prepare(dn)
  def run(t, tree):
+       t._debug('[----------------------------------------')
        def stdouterr(oe):
                idstr = t.what + '-' + oe
                if opts.output_dir is not None and opts.output_dir.tb:
@@ -771,24 +977,41 @@ class Test:
                        use_dir = testbed.scratch
                return RelativeOutputFile(idstr, use_dir, idstr)
 
+       t.act.work.write(True)
+
        af = RelativeInputFile(t.what, tree, t.path)
        so = stdouterr('stdout')
        se = stdouterr('stderr')
-       rc = testbed.execute('test-'+t.what,
-               [opts.user_wrap(af.read(True))],
-               so=so.write(True), se=se.write(True), cwd=tree.write(True))
-                       
-       stab = os.stat(se.read())
+       tf = af.read(True)
+       if 'needs-root' not in t.restrictions:
+               tf = opts.user_wrap(tf)
+       rc = testbed.execute('test-'+t.what, [tf],
+               so=so.write(True), se=se.write(True), cwd=tree.read(True))
+
+       so_read = so.read()
+       se_read = se.read()
+
+       t._debug(' - - - - - - - - - - results - - - - - - - - - -')
+       stab = os.stat(se_read)
        if stab.st_size != 0:
-               l = file(se.read()).readline()
+               l = open(se_read).readline()
                l = l.rstrip('\n \t\r')
                if len(l) > 40: l = l[:40] + '...'
                t.reportfail('status: %d, stderr: %s' % (rc, l))
+               t._debug(' - - - - - - - - - - stderr - - - - - - - - - -')
+               debug_file(se_read)
        elif rc != 0:
                t.reportfail('non-zero exit status %d' % rc)
        else:
                t.report('PASS')
 
+       stab = os.stat(so_read)
+       if stab.st_size != 0:
+               t._debug(' - - - - - - - - - - stdout - - - - - - - - - -')
+               debug_file(so_read)
+
+       t._debug('----------------------------------------]')
+
 def read_control(act, tree, control_override):
        stanzas = [ ]
 
@@ -799,7 +1022,7 @@ def read_control(act, tree, control_override):
                control_af = RelativeInputFile(act.what+'-testcontrol',
                        tree, 'debian/tests/control')
        try:
-               control = file(control_af.read(), 'r')
+               control = open(control_af.read(), 'r')
        except OSError, oe:
                if oe[0] != errno.ENOENT: raise
                return []
@@ -855,7 +1078,8 @@ def read_control(act, tree, control_override):
                        tnames = string.join(tnames).split()
                        base = {
                                'restrictions': [],
-                               'testsdir': 'debian/tests'
+                               'testsdir': 'debian/tests',
+                               'depends' : '_'
                        }
                        for fname in stz.keys():
                                if fname.startswith(' '): continue
@@ -867,7 +1091,7 @@ def read_control(act, tree, control_override):
                                f = fclass(stz, fname, base, tnames, vl)
                                f.parse()
                        for tname in tnames:
-                               t = Test(tname, base, act.what)
+                               t = Test(tname, base, act)
                                stz[' tests'].append(t)
                except Unsupported, u:
                        for tname in tnames: u.report(tname)
@@ -876,24 +1100,31 @@ def read_control(act, tree, control_override):
        return stanzas
 
 def print_exception(ei, msgprefix=''):
-       if msgprefix: print >>sys.stderr, msgprefix
+       if msgprefix: pstderr(msgprefix)
        (et, q, tb) = ei
        if et is Quit:
-               print >>sys.stderr, 'adt-run:', q.m
+               pstderr('adt-run: ' + q.m)
                return q.ec
        else:
-               print >>sys.stderr, "adt-run: unexpected, exceptional, error:"
-               traceback.print_exc()
+               pstderr("adt-run: unexpected, exceptional, error:")
+               traceback.print_exc(None, sys.stderr)
+               if trace_stream is not None:
+                       traceback.print_exc(None, trace_stream)
                return 20
 
 def cleanup():
+       global trace_stream
        try:
                rm_ec = 0
                if opts.tmpdir is None and tmpdir is not None:
                        rmtree('tmpdir', tmpdir)
                if testbed is not None:
+                       testbed.reset_apt()
                        testbed.stop()
                if rm_ec: bomb('rm -rf -- %s failed, code %d' % (tmpdir, ec))
+               if trace_stream is not None:
+                       trace_stream.close()
+                       trace_stream = None
        except:
                print_exception(sys.exc_info(),
                        '\nadt-run: error cleaning up:\n')
@@ -903,17 +1134,15 @@ def cleanup():
 
 def determine_package(act):
        cmd = 'dpkg-deb --info --'.split(' ')+[act.af.read(),'control']
-       running = Popen(cmd, stdout=PIPE)
-       output = running.communicate()[0]
-       rc = running.wait()
+       (rc, output) = subprocess_cooked(cmd, stdout=subprocess.PIPE)
        if rc: badpkg('failed to parse binary package, code %d' % rc)
        re = regexp.compile('^\s*Package\s*:\s*([0-9a-z][-+.0-9a-z]*)\s*$')
        act.pkg = None
-       for l in '\n'.split(output):
-               m = re.match(output)
+       for l in output.split('\n'):
+               m = re.match(l)
                if not m: continue
                if act.pkg: badpkg('two Package: lines in control file')
-               act.pkg = m.groups
+               act.pkg = m.groups()[0]
        if not act.pkg: badpkg('no good Package: line in control file')
 
 class Binaries:
@@ -946,8 +1175,8 @@ class Binaries:
        mkdir_okexist(opts.gnupghome, 0700)
 
        script = '''
+  exec >&2
   cd "$1"
-  exec >key-gen-log 2>&1
   cat <<"END" >key-gen-params
 Key-Type: DSA
 Key-Length: 1024
@@ -960,16 +1189,50 @@ END
   gpg --homedir="$1" --batch --gen-key key-gen-params
                '''
        cmdl = ['sh','-ec',script,'x',opts.gnupghome]
-       debug_subprocess('genkey', cmdl, script=script)
-       rc = subprocess.call(cmdl)
+       rc = subprocess_cooked(cmdl, dbg=(genkey,script))[0]
        if rc:
                try:
                        f = open(opts.gnupghome+'/key-gen-log')
                        tp = file.read()
                except OSError, e: tp = e
-               print >>sys.stderr, tp
+               pstderr(tp)
                bomb('key generation failed, code %d' % rc)
 
+ def apt_configs(b):
+       return {
+               "Dir::Etc::sourcelist": b.dir.read(True)+'sources.list',
+       }
+
+ def apt_pkg_gdebi_script(b, arg, middle):
+       script = [
+               'import apt_pkg',
+               'import urllib',
+               'arg = urllib.unquote("%s")' % urllib.quote(arg),
+               ]
+       for (k,v) in b.apt_configs().iteritems():
+               v = urllib.quote(v)
+               script.append('apt_pkg.Config.Set("%s",urllib.unquote("%s"))'
+                               % (k, v))
+       script += [
+               'from GDebi.Cache import Cache',
+               'cache = Cache()',
+               ]
+       for m in middle:
+               script += m + [
+               'print res',
+               'print d.missingDeps',
+               'print d.requiredChanges',
+               'assert(res)',
+               'cache.commit()',
+               ''
+               ]
+       return '\n'.join(script)
+ def apt_get(b):
+       ag = ['apt-get','-qy']
+       for kv in b.apt_configs().iteritems():
+               ag += ['-o', '%s=%s' % kv]
+       return ag
+
  def reset(b):
        b._debug('reset')
        rmtree('binaries', b.dir.read())
@@ -977,6 +1240,7 @@ END
        b.dir.write()
        b.install = []
        b.blamed = []
+       b.registered = set()
 
  def register(b, act, pkg, af, forwhat, blamed):
        b._debug('register what=%s deb_%s=%s pkg=%s af=%s'
@@ -1001,74 +1265,95 @@ END
        if act.ah['deb_'+forwhat] == 'install':
                b.install.append(pkg)
 
+       b.registered.add(pkg)
+
  def publish(b):
        b._debug('publish')
 
        script = '''
+  exec >&2
   cd "$1"
   apt-ftparchive packages . >Packages
-  gzip -f Packages
+  gzip <Packages >Packages.gz
   apt-ftparchive release . >Release
+  rm -f Release.gpg
   gpg --homedir="$2" --batch --detach-sign --armour -o Release.gpg Release
   gpg --homedir="$2" --batch --export >archive-key.pgp
                '''
        cmdl = ['sh','-ec',script,'x',b.dir.write(),opts.gnupghome]
-       debug_subprocess('ftparchive', cmdl, script)
-       rc = subprocess.call(cmdl)
+       rc = subprocess_cooked(cmdl, dbg=('ftparchive',script))[0]
        if rc: bomb('apt-ftparchive or signature failed, code %d' % rc)
 
        b.dir.invalidate(True)
        apt_source = b.dir.read(True)
 
+       so = TemporaryFile('vlds')
        script = '''
+  exec 3>&1 >&2
   apt-key add archive-key.pgp
-  echo "deb file:///'''+apt_source+'''/ /" >/etc/apt/sources.list.d/autopkgtest
+  echo "deb file://'''+apt_source+''' /" >sources.list
+  cat /etc/apt/sources.list >>sources.list
+  if [ "x`ls /var/lib/dpkg/updates`" != x ]; then
+    echo >&2 "/var/lib/dpkg/updates contains some files, aargh"; exit 1
+  fi
+  '''+ ' '.join(b.apt_get()) +''' update >&2
+  cat /var/lib/dpkg/status >&3
                '''
-       debug_subprocess('apt-key', script=script)
-       (rc,se) = testbed.execute('apt-key',
-                               ['sh','-ec',script],
-                               cwd=b.dir.write(True))
-       if rc: bomb('apt setup failed with exit code %d' % rc, se)
+       testbed.mungeing_apt()
+       rc = testbed.execute('apt-key', ['sh','-ec',script],
+                               so=so.write(True), cwd=b.dir.write(True),
+                               script=script)
+       if rc: bomb('apt setup failed with exit code %d' % rc)
 
        testbed.blamed += b.blamed
 
+       b._debug('publish reinstall checking...')
+       pkgs_reinstall = set()
+       pkg = None
+       for l in open(so.read()):
+               if l.startswith('Package: '):
+                       pkg = l[9:].rstrip()
+               elif l.startswith('Status: install '):
+                       if pkg in b.registered:
+                               pkgs_reinstall.add(pkg)
+                               b._debug(' publish reinstall needs '+pkg)
+
+       if pkgs_reinstall:
+               for pkg in pkgs_reinstall: testbed.blame(pkg)
+               what = 'apt-get-reinstall'
+               cmdl = (b.apt_get() + ['--reinstall','install'] +
+                       [pkg for pkg in pkgs_reinstall])
+               rc = testbed.execute(what, cmdl, script=None)
+               if rc: badpkg("installation of basic binarries failed,"
+                               " exit code %d" % rc)
+
+       b._debug('publish install...')
        for pkg in b.install:
-               b._debug('publish install %s' % pkg)
+               what = 'apt-get-install-%s' % pkg
                testbed.blame(pkg)
-               debug_subprocess('apt-get(b.install)', script=script)
-               (rc,se) = testbed.execute('install-%s'+act.what,
-                       ['apt-get','-qy','install',pkg])
+               cmdl = b.apt_get() + ['install',pkg]
+               rc = testbed.execute(what, cmdl, script=None)
                if rc: badpkg("installation of %s failed, exit code %d"
-                               % (pkg, rc), se)
+                               % (pkg, rc))
 
        b._debug('publish done')
 
 #---------- processing of sources (building)
 
-def source_rules_command(act,script,what,which,work,results_lines=0):
-       if opts.debug:
-               trace = "%s-%s-trace" % (what,which)
-               script = [      "mkfifo -m600 "+trace,
-                               "tee <"+trace+" /dev/stderr >&4 &",
-                               "exec >"+trace+" 2>&1"  ] + script
-
+def source_rules_command(act,script,what,which,work,cwd,
+                               results_lines=0,xargs=[]):
        script = [      "exec 3>&1 >&2",
                        "set -x"        ] + script
        script = '\n'.join(script)
        so = TemporaryFile('%s-%s-results' % (what,which))
-       se = TemporaryFile('%s-%s-log' % (what,which))
-       debug_subprocess('source-rules-command/%s/%s' % (act.what, which),
-                       script=script)
        rc = testbed.execute('%s-%s' % (what,which),
-                       ['sh','-xec',script],
-                       so=so.write(True), se=se.write(True),
-                       cwd= work.write(True), dump_fd=4)
-       results = file(so.read()).read().rstrip('\n').split("\n")
-       se = file(se.read()).read()
-       if rc: badpkg("%s failed with exit code %d" % (which,rc), se)
+                       ['sh','-ec',script]+xargs, script=script,
+                       so=so.write(True), cwd=cwd)
+       results = open(so.read()).read().rstrip('\n').split("\n")
+       if rc: badpkg("%s failed with exit code %d" % (which,rc))
        if results_lines is not None and len(results) != results_lines:
                badpkg("got %d lines of results from %s where %d expected"
-                       % (len(results), which, results_lines), se)
+                       % (len(results), which, results_lines))
        if results_lines==1: return results[0]
        return results
 
@@ -1078,61 +1363,119 @@ def build_source(act):
        testbed.needs_reset()
 
        what = act.what
-       dsc = act.af
-       basename = dsc.spec
-
-       dsc_file = open(dsc.read())
-       in_files = False
-       fre = regexp.compile('^\s+[0-9a-f]+\s+\d+\s+([^/.][^/]*)$')
-       for l in dsc_file:
-               l = l.rstrip('\n')
-               if l.startswith('Files:'): in_files = True; continue
-               elif l.startswith('#'): pass
-               elif not l.startswith(' '):
-                       in_files = False
-                       if l.startswith('Source:'):
-                               act.blame = 'dsc:'+l[7:].strip()
-                               testbed.blame(act.blame)
-               if not in_files: continue
-
-               m = fre.match(l)
-               if not m: badpkg(".dsc contains unparseable line"
-                               " in Files: `%s'" % l)
-               leaf = m.groups(0)[0]
-               subfile = RelativeInputFile(what+'/'+leaf, dsc, leaf,
-                               sibling=True)
-               subfile.read(True)
-       dsc.read(True)
-       
+       basename = act.af.spec
+
+       if act.kind == 'dsc':
+               dsc = act.af
+               dsc_file = open(dsc.read())
+               in_files = False
+               fre = regexp.compile('^\s+[0-9a-f]+\s+\d+\s+([^/.][^/]*)$')
+               for l in dsc_file:
+                       l = l.rstrip('\n')
+                       if l.startswith('Files:'): in_files = True; continue
+                       elif l.startswith('#'): pass
+                       elif not l.startswith(' '):
+                               in_files = False
+                               if l.startswith('Source:'):
+                                       act.blame = 'dsc:'+l[7:].strip()
+                                       testbed.blame(act.blame)
+                       if not in_files: continue
+
+                       m = fre.match(l)
+                       if not m: badpkg(".dsc contains unparseable line"
+                                       " in Files: `%s'" % l)
+                       leaf = m.groups(0)[0]
+                       subfile = RelativeInputFile(what+'/'+leaf, dsc, leaf,
+                                       sibling=True)
+                       subfile.read(True)
+               dsc.read(True)
+
+       if act.kind == 'ubtree':
+               debiancontrol = RelativeInputFile(what+'-debiancontrol',
+                       act.af, 'debian/control')
+               dsc = TemporaryFile(what+'-fakedsc')
+               dsc_w = open(dsc.write(), 'w')
+               for l in open(debiancontrol.read()):
+                       l = l.rstrip('\n')
+                       if not len(l): break
+                       print >>dsc_w, l
+               print >>dsc_w, 'Binary: none-so-this-is-not-a-package-name'
+               dsc_w.close()
+
+       script = binaries.apt_pkg_gdebi_script(
+               dsc.read(True), [[
+               'from GDebi.DscSrcPackage import DscSrcPackage',
+               'd = DscSrcPackage(cache, arg)',
+               'res = d.checkDeb()',
+                ],[
+               'from GDebi.DebPackage import DebPackage',
+               'd = DebPackage(cache)',
+               'res = d.satisfyDependsStr("build-essential")',
+               ]])
+
+       cmdl = ['python','-c',script]
+       whatp = what+'-builddeps'
+       rc = testbed.execute(what, cmdl, script=script)
+       if rc: badpkg('build-depends install failed, exit code %d' % rc)
+
        work = TemporaryDir(what+'-build')
 
        script = [
-                       'cd '+work.write(True),
-                       'apt-get update >&4',
-                       'apt-get -qy install build-essential >&4',
-                       'gdebi '+dsc.read(True) +'>&4 ||apt-get -y install dpatch bison >&4', # fixme fixme
-                       'dpkg-source -x '+dsc.read(True)+' >&4',
+               'arg="$1"',
+               'origpwd=`pwd`',
+               'cd '+work.write(True)
+       ]
+
+       if act.kind == 'ubtree':
+               spec = '%s/real-tree' % work.write(True)
+               create_command = '''
+                       rm -rf "$spec"
+                       mkdir "$spec"
+                       cp -rP --preserve=timestamps,links -- "$origpwd"/. "$spec"/.
+                       '''
+               initcwd = act.af.read(True)
+
+       if act.kind == 'dsc':
+               spec = dsc.read(True)
+               create_command = '''
+                       dpkg-source -x $spec
+                       '''
+               initcwd = work.write(True)
+
+       if opts.user: script += [
+                       'chown '+opts.user+' .',
+                       'spec="$arg" '+opts.user_wrap(create_command)
+                       ]
+       else: script += [
+                       'spec="$arg"',
+                       create_command
+               ]
+
+       script += [
                        'cd */.',
                        'dpkg-checkbuilddeps',
                        'pwd >&3',
                        opts.user_wrap('debian/rules build'),
-       ]
-       result_pwd = source_rules_command(act,script,what,'build',work,1)
+               ]
+       result_pwd = source_rules_command(act,script,what,'build',work,
+                       cwd=initcwd, results_lines=1, xargs=['x',spec])
 
        if os.path.dirname(result_pwd)+'/' != work.read(True):
                badpkg("results dir `%s' is not in expected parent dir `%s'"
                        % (result_pwd, work.read(True)))
 
+       act.work = work
        act.tests_tree = InputDir(what+'-tests-tree',
                                work.read(True)+os.path.basename(result_pwd),
                                True)
        if act.ah['dsc_tests']:
                act.tests_tree.read()
-               act.tests_tree.invalidate(True)
+               testbed.register_ephemeral(act.work)
+               testbed.register_ephemeral(act.tests_tree)
 
        act.blamed = copy.copy(testbed.blamed)
 
-       def debug_b(m): debug('* <dsc:%s> %s' % (act.what, m))
+       def debug_b(m): debug('* <%s:%s> %s' % (act.kind, act.what, m))
        act.binaries = []
        filter = act.ah['dsc_filter']
        debug_b('filter=%s' % filter)
@@ -1144,7 +1487,7 @@ def build_source(act):
                        'echo *.deb >&3',
                        ]
                result_debs = source_rules_command(act,script,what,
-                               'binary',work,1)
+                               'binary',work,work.write(True),results_lines=1)
                if result_debs == '*': debs = []
                else: debs = result_debs.split(' ')
                debug_b('debs='+`debs`)
@@ -1182,6 +1525,9 @@ def process_actions():
        testbed.open()
        binaries = Binaries()
 
+       for act in opts.actions:
+               testbed.register_ephemeral(act.af)
+
        binaries.reset()
 
        debug_a1('builds ...')
@@ -1189,15 +1535,17 @@ def process_actions():
                debug_a2('%s %s' %
                        (act.kind, act.what))
 
-               testbed.prepare()
+               testbed.prepare([])
                if act.kind == 'deb':
-                       blame('arg:'+act.af.spec)
+                       testbed.blame('arg:'+act.af.spec)
                        determine_package(act)
-                       blame('deb:'+act.pkg)
+                       testbed.blame('deb:'+act.pkg)
                        binaries.register(act,act.pkg,act.af,
                                'forbuilds',testbed.blamed)
-               if act.kind == 'dsc':
+               if act.kind == 'dsc' or act.kind == 'ubtree':
                        build_source(act)
+               if act.kind == 'tree':
+                       act.binaries = []
 
        debug_a1('builds done.')
 
@@ -1214,10 +1562,11 @@ def process_actions():
                if act.kind == 'deb':
                        binaries.register(act,act.pkg,act.af,'fortests',
                                ['deb:'+act.pkg])
-               if act.kind == 'dsc':
+               if act.kind == 'dsc' or act.kind == 'ubtree':
                        for (pkg,bin) in act.binaries:
                                binaries.register(act,pkg,bin,'fortests',
                                        act.blamed)
+               if act.kind == 'dsc':
                        if act.ah['dsc_tests']:
                                debug_a3('read control ...')
                                stanzas = read_control(act, act.tests_tree,
@@ -1226,7 +1575,7 @@ def process_actions():
                                debug_a3('run_tests ...')
                                run_tests(stanzas, act.tests_tree)
                        control_override = None
-               if act.kind == 'tree':
+               if act.kind == 'tree' or act.kind == 'ubtree':
                        testbed.blame('arg:'+act.af.spec)
                        stanzas = read_control(act, act.af, control_override)
                        debug_a3('run_tests ...')
@@ -1242,6 +1591,7 @@ def main():
        except SystemExit, se:
                os._exit(20)
        try:
+               setup_trace()
                testbed = Testbed()
                testbed.start()
                finalise_options()