Attachment 268691 Details for Bug 399261 – mock setup log

mock setup log

root.log (text/plain), 103.96 KB, created by Jan Safranek on 2007-11-26 09:40:42 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jan Safranek

Created: 2007-11-26 09:40:42 UTC

Size: 103.96 KB

patch

obsolete

>2007-11-26 09:27:39,423 - trace_decorator.py:30:DEBUG: LEAVE _resetLogging --> None
>
>2007-11-26 09:27:39,424 - backend.py:168:DEBUG: rootdir = /var/lib/mock/ldap-i386/root
>2007-11-26 09:27:39,424 - backend.py:169:DEBUG: resultdir = /var/lib/mock/ldap-i386/result
>2007-11-26 09:27:39,424 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'preinit'), {})
>2007-11-26 09:27:39,424 - trace_decorator.py:20:DEBUG: ENTER: _ccachePreInitHook((<ccache.CCache object at 0x886c90>,), {})
>2007-11-26 09:27:39,424 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/tmp/ccache',), {})
>2007-11-26 09:27:39,425 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:39,425 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:39,425 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:39,425 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/cache/ldap-i386/ccache/',), {})
>2007-11-26 09:27:39,426 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/cache/ldap-i386/ccache/
>2007-11-26 09:27:39,426 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:39,426 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/cc'), {})
>2007-11-26 09:27:39,426 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,427 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-cc'), {})
>2007-11-26 09:27:39,427 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,427 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-cc'), {})
>2007-11-26 09:27:39,427 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,427 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/gcc'), {})
>2007-11-26 09:27:39,428 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,428 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-gcc'), {})
>2007-11-26 09:27:39,428 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,428 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-gcc'), {})
>2007-11-26 09:27:39,429 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,429 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/gcc296'), {})
>2007-11-26 09:27:39,429 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,429 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-gcc296'), {})
>2007-11-26 09:27:39,430 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,430 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-gcc296'), {})
>2007-11-26 09:27:39,430 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,430 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/gcc32'), {})
>2007-11-26 09:27:39,430 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,431 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-gcc32'), {})
>2007-11-26 09:27:39,431 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,431 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-gcc32'), {})
>2007-11-26 09:27:39,431 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,432 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/gcc33'), {})
>2007-11-26 09:27:39,432 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,432 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-gcc33'), {})
>2007-11-26 09:27:39,432 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,432 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-gcc33'), {})
>2007-11-26 09:27:39,433 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,433 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/gcc34'), {})
>2007-11-26 09:27:39,433 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,433 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-gcc34'), {})
>2007-11-26 09:27:39,434 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,434 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-gcc34'), {})
>2007-11-26 09:27:39,434 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,434 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++'), {})
>2007-11-26 09:27:39,435 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,435 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++'), {})
>2007-11-26 09:27:39,435 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,435 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++'), {})
>2007-11-26 09:27:39,436 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,436 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/c++'), {})
>2007-11-26 09:27:39,436 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,436 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-c++'), {})
>2007-11-26 09:27:39,436 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,437 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-c++'), {})
>2007-11-26 09:27:39,437 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,437 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/c++32'), {})
>2007-11-26 09:27:39,437 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,438 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-c++32'), {})
>2007-11-26 09:27:39,438 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,438 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-c++32'), {})
>2007-11-26 09:27:39,438 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,439 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/c++33'), {})
>2007-11-26 09:27:39,439 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,439 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-c++33'), {})
>2007-11-26 09:27:39,439 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,439 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-c++33'), {})
>2007-11-26 09:27:39,439 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,440 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/c++34'), {})
>2007-11-26 09:27:39,440 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,440 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-c++34'), {})
>2007-11-26 09:27:39,440 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,440 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-c++34'), {})
>2007-11-26 09:27:39,440 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,440 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++296'), {})
>2007-11-26 09:27:39,441 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,441 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++296'), {})
>2007-11-26 09:27:39,441 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,441 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++296'), {})
>2007-11-26 09:27:39,441 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,441 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++32'), {})
>2007-11-26 09:27:39,442 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,442 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++32'), {})
>2007-11-26 09:27:39,442 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,442 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++32'), {})
>2007-11-26 09:27:39,442 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,442 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++33'), {})
>2007-11-26 09:27:39,442 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,443 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++33'), {})
>2007-11-26 09:27:39,443 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,443 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++33'), {})
>2007-11-26 09:27:39,443 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,443 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++34'), {})
>2007-11-26 09:27:39,443 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,444 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++34'), {})
>2007-11-26 09:27:39,444 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,444 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++34'), {})
>2007-11-26 09:27:39,444 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,444 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/g++-libstdc++-so_7'), {})
>2007-11-26 09:27:39,444 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,444 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/x86_64-redhat-linux-g++-libstdc++-so_7'), {})
>2007-11-26 09:27:39,445 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,445 - trace_decorator.py:20:DEBUG: ENTER: forceLink(('/usr/bin/ccache', '/var/lib/mock/cache/ldap-i386/ccache/i386-redhat-linux-g++-libstdc++-so_7'), {})
>2007-11-26 09:27:39,445 - trace_decorator.py:30:DEBUG: LEAVE forceLink --> None
>
>2007-11-26 09:27:39,445 - trace_decorator.py:30:DEBUG: LEAVE _ccachePreInitHook --> None
>
>2007-11-26 09:27:39,445 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePreInitHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:39,445 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/cache/yum',), {})
>2007-11-26 09:27:39,445 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:39,446 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:39,446 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:39,446 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/cache/ldap-i386/yum_cache/',), {})
>2007-11-26 09:27:39,446 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/cache/ldap-i386/yum_cache/
>2007-11-26 09:27:39,446 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:39,447 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePreYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:39,447 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePreYumHook --> None
>
>2007-11-26 09:27:39,447 - trace_decorator.py:20:DEBUG: ENTER: state((<mock.backend.Root object at 0x882890>, 'enabled yum cache, cleaning yum metadata'), {})
>2007-11-26 09:27:39,447 - trace_decorator.py:30:DEBUG: LEAVE state --> enabled yum cache, cleaning yum metadata
>
>2007-11-26 09:27:39,473 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePostYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:39,474 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePostYumHook --> None
>
>2007-11-26 09:27:39,474 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePreInitHook --> None
>
>2007-11-26 09:27:39,474 - trace_decorator.py:20:DEBUG: ENTER: _rootCachePreInitHook((<root_cache.RootCache object at 0x892490>,), {})
>2007-11-26 09:27:39,474 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/cache/ldap-i386/root_cache/',), {})
>2007-11-26 09:27:39,474 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/cache/ldap-i386/root_cache/
>2007-11-26 09:27:39,474 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:39,474 - trace_decorator.py:20:DEBUG: ENTER: state((<mock.backend.Root object at 0x882890>, 'enabling root cache'), {})
>2007-11-26 09:27:39,475 - trace_decorator.py:30:DEBUG: LEAVE state --> enabling root cache
>
>2007-11-26 09:27:39,475 - trace_decorator.py:20:DEBUG: ENTER: state((<mock.backend.Root object at 0x882890>, 'unpacking cache'), {})
>2007-11-26 09:27:39,475 - trace_decorator.py:30:DEBUG: LEAVE state --> unpacking cache
>
>2007-11-26 09:27:39,475 - trace_decorator.py:20:DEBUG: ENTER: _rootCacheLock((<root_cache.RootCache object at 0x892490>, 1), {})
>2007-11-26 09:27:39,475 - trace_decorator.py:30:DEBUG: LEAVE _rootCacheLock --> None
>
>2007-11-26 09:27:39,475 - trace_decorator.py:20:DEBUG: ENTER: do(('tar xzf /var/lib/mock/cache/ldap-i386/root_cache/cache.tar.gz -C /var/lib/mock/ldap-i386/root', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:39,475 - util.py:196:DEBUG: Run cmd: tar xzf /var/lib/mock/cache/ldap-i386/root_cache/cache.tar.gz -C /var/lib/mock/ldap-i386/root
>2007-11-26 09:27:39,476 - util.py:202:DEBUG: Executing timeout(0): tar xzf /var/lib/mock/cache/ldap-i386/root_cache/cache.tar.gz -C /var/lib/mock/ldap-i386/root
>2007-11-26 09:27:39,477 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:39,477 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:39,478 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:39,478 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,057 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,057 - trace_decorator.py:20:DEBUG: ENTER: _rootCacheUnlock((<root_cache.RootCache object at 0x892490>,), {})
>2007-11-26 09:27:50,057 - trace_decorator.py:30:DEBUG: LEAVE _rootCacheUnlock --> None
>
>2007-11-26 09:27:50,058 - trace_decorator.py:30:DEBUG: LEAVE _rootCachePreInitHook --> None
>
>2007-11-26 09:27:50,058 - trace_decorator.py:20:DEBUG: ENTER: _bindMountPreInitHook((<bind_mount.BindMount object at 0x892ad0>,), {})
>2007-11-26 09:27:50,058 - trace_decorator.py:30:DEBUG: LEAVE _bindMountPreInitHook --> None
>
>2007-11-26 09:27:50,058 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:50,058 - backend.py:175:INFO: create skeleton dirs
>2007-11-26 09:27:50,058 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/lib/rpm',), {})
>2007-11-26 09:27:50,058 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/lib/rpm
>2007-11-26 09:27:50,059 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,059 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/lib/yum',), {})
>2007-11-26 09:27:50,059 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/lib/yum
>2007-11-26 09:27:50,059 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,059 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/log',), {})
>2007-11-26 09:27:50,059 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/log
>2007-11-26 09:27:50,059 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,059 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/lock/rpm',), {})
>2007-11-26 09:27:50,060 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/lock/rpm
>2007-11-26 09:27:50,060 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,060 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/etc/rpm',), {})
>2007-11-26 09:27:50,060 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/etc/rpm
>2007-11-26 09:27:50,060 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,060 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/tmp',), {})
>2007-11-26 09:27:50,060 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/tmp
>2007-11-26 09:27:50,061 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,061 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/var/tmp',), {})
>2007-11-26 09:27:50,061 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/var/tmp
>2007-11-26 09:27:50,061 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,061 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/etc/yum.repos.d',), {})
>2007-11-26 09:27:50,061 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/etc/yum.repos.d
>2007-11-26 09:27:50,061 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,061 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/etc/yum',), {})
>2007-11-26 09:27:50,062 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/etc/yum
>2007-11-26 09:27:50,062 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,062 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/proc',), {})
>2007-11-26 09:27:50,062 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:50,062 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,062 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/dev/pts',), {})
>2007-11-26 09:27:50,062 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,062 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,063 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/sys',), {})
>2007-11-26 09:27:50,063 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:50,063 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,063 - backend.py:193:INFO: touch required files
>2007-11-26 09:27:50,063 - trace_decorator.py:20:DEBUG: ENTER: touch(('/var/lib/mock/ldap-i386/root/etc/mtab',), {})
>2007-11-26 09:27:50,063 - util.py:49:DEBUG: touching file: /var/lib/mock/ldap-i386/root/etc/mtab
>2007-11-26 09:27:50,063 - trace_decorator.py:30:DEBUG: LEAVE touch --> None
>
>2007-11-26 09:27:50,063 - trace_decorator.py:20:DEBUG: ENTER: touch(('/var/lib/mock/ldap-i386/root/etc/fstab',), {})
>2007-11-26 09:27:50,064 - util.py:49:DEBUG: touching file: /var/lib/mock/ldap-i386/root/etc/fstab
>2007-11-26 09:27:50,064 - trace_decorator.py:30:DEBUG: LEAVE touch --> None
>
>2007-11-26 09:27:50,064 - trace_decorator.py:20:DEBUG: ENTER: touch(('/var/lib/mock/ldap-i386/root/var/log/yum.log',), {})
>2007-11-26 09:27:50,064 - util.py:49:DEBUG: touching file: /var/lib/mock/ldap-i386/root/var/log/yum.log
>2007-11-26 09:27:50,064 - trace_decorator.py:30:DEBUG: LEAVE touch --> None
>
>2007-11-26 09:27:50,064 - backend.py:201:INFO: configure yum
>2007-11-26 09:27:50,065 - trace_decorator.py:20:DEBUG: ENTER: rmtree(('/var/lib/mock/ldap-i386/root/dev',), {})
>2007-11-26 09:27:50,066 - trace_decorator.py:30:DEBUG: LEAVE rmtree --> None
>
>2007-11-26 09:27:50,066 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root/dev/pts',), {})
>2007-11-26 09:27:50,066 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,066 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,066 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:50,067 - backend.py:247:INFO: run yum
>2007-11-26 09:27:50,067 - trace_decorator.py:20:DEBUG: ENTER: _mountall((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:27:50,067 - backend.py:424:INFO: mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:50,067 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,067 - util.py:196:DEBUG: Run cmd: mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:50,067 - util.py:202:DEBUG: Executing timeout(0): mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:50,069 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,069 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,069 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,070 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,092 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,092 - backend.py:424:INFO: mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,092 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,092 - util.py:196:DEBUG: Run cmd: mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,092 - util.py:202:DEBUG: Executing timeout(0): mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:50,094 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,094 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,094 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,094 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,114 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,114 - backend.py:424:INFO: mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:50,115 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,115 - util.py:196:DEBUG: Run cmd: mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:50,115 - util.py:202:DEBUG: Executing timeout(0): mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:50,116 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,117 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,117 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,117 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,140 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,140 - backend.py:424:INFO: mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:50,140 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,140 - util.py:196:DEBUG: Run cmd: mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:50,140 - util.py:202:DEBUG: Executing timeout(0): mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:50,142 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,142 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,143 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,143 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,151 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,152 - backend.py:424:INFO: mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:50,152 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,152 - util.py:196:DEBUG: Run cmd: mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:50,152 - util.py:202:DEBUG: Executing timeout(0): mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:50,153 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,154 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,154 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,154 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:50,163 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:50,164 - trace_decorator.py:30:DEBUG: LEAVE _mountall --> None
>
>2007-11-26 09:27:50,164 - trace_decorator.py:20:DEBUG: ENTER: _yum((<mock.backend.Root object at 0x882890>, 'update', 0), {})
>2007-11-26 09:27:50,164 - backend.py:439:INFO: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root update
>2007-11-26 09:27:50,164 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'preyum'), {})
>2007-11-26 09:27:50,164 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePreYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:50,164 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePreYumHook --> None
>
>2007-11-26 09:27:50,164 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:50,164 - trace_decorator.py:20:DEBUG: ENTER: do(('/usr/bin/yum --installroot /var/lib/mock/ldap-i386/root update', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:50,165 - util.py:196:DEBUG: Run cmd: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root update
>2007-11-26 09:27:50,165 - util.py:202:DEBUG: Executing timeout(0): /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root update
>2007-11-26 09:27:50,166 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:50,167 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:50,167 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:50,167 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,346 - util.py:218:DEBUG: 
>2007-11-26 09:27:56,347 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:27:56,347 - util.py:218:DEBUG:  Package                 Arch       Version          Repository        Size 
>2007-11-26 09:27:56,347 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:27:56,347 - util.py:218:DEBUG: Updating:
>2007-11-26 09:27:56,347 - util.py:218:DEBUG:  coreutils               i386       6.9-14.fc9       fedora            3.3 M
>2007-11-26 09:27:56,347 - util.py:218:DEBUG:  kernel-headers          i386       2.6.24-0.42.rc3.git1.fc9  fedora            671 k
>2007-11-26 09:27:56,347 - util.py:218:DEBUG:  less                    i386       416-1.fc9        fedora            106 k
>2007-11-26 09:27:56,347 - util.py:218:DEBUG:  zlib                    i386       1.2.3-16.fc9     fedora             72 k
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: 
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: Transaction Summary
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: Install      0 Package(s)         
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: Update       4 Package(s)         
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: Remove       0 Package(s)         
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: 
>2007-11-26 09:27:56,348 - util.py:218:DEBUG: Total download size: 4.2 M
>2007-11-26 09:27:56,349 - util.py:218:DEBUG: 
>2007-11-26 09:27:56,349 - util.py:218:DEBUG: Updated: coreutils.i386 0:6.9-14.fc9 kernel-headers.i386 0:2.6.24-0.42.rc3.git1.fc9 less.i386 0:416-1.fc9 zlib.i386 0:1.2.3-16.fc9
>2007-11-26 09:27:56,349 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,349 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'postyum'), {})
>2007-11-26 09:27:56,349 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePostYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:56,349 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePostYumHook --> None
>
>2007-11-26 09:27:56,349 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:56,350 - trace_decorator.py:30:DEBUG: LEAVE _yum --> 
>
>2007-11-26 09:27:56,350 - trace_decorator.py:20:DEBUG: ENTER: _umountall((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:27:56,350 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,350 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/proc', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:27:56,350 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,350 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,351 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,352 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,352 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,352 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,363 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,363 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,363 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/dev/pts', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:27:56,363 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,364 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,365 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,366 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,366 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,367 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,376 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,376 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,376 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/sys', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:27:56,376 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,377 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,378 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,378 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,378 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,378 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,387 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,387 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,387 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/tmp/ccache', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:27:56,387 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,387 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,389 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,389 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,389 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,390 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,398 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,399 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,399 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/var/cache/yum', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:27:56,399 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,399 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,400 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,401 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,401 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,401 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,409 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,409 - trace_decorator.py:30:DEBUG: LEAVE _umountall --> None
>
>2007-11-26 09:27:56,410 - trace_decorator.py:20:DEBUG: ENTER: _makeBuildUser((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:27:56,410 - trace_decorator.py:20:DEBUG: ENTER: rmtree(('/builddir',), {})
>2007-11-26 09:27:56,410 - trace_decorator.py:30:DEBUG: LEAVE rmtree --> None
>
>2007-11-26 09:27:56,410 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, '/usr/sbin/userdel -r mockbuild', ''), {'raiseExc': False})
>2007-11-26 09:27:56,410 - trace_decorator.py:20:DEBUG: ENTER: do(('/usr/sbin/userdel -r mockbuild', '/var/lib/mock/ldap-i386/root', 0, False, 0, None, None, None), {})
>2007-11-26 09:27:56,410 - util.py:196:DEBUG: Run cmd: /usr/sbin/userdel -r mockbuild
>2007-11-26 09:27:56,410 - util.py:202:DEBUG: Executing timeout(0): /usr/sbin/userdel -r mockbuild
>2007-11-26 09:27:56,412 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:27:56,412 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:56,412 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 03:27:56,413 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,430 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,430 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:27:56,431 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, '/usr/sbin/groupdel mockbuild', ''), {'raiseExc': False})
>2007-11-26 09:27:56,431 - trace_decorator.py:20:DEBUG: ENTER: do(('/usr/sbin/groupdel mockbuild', '/var/lib/mock/ldap-i386/root', 0, False, 0, None, None, None), {})
>2007-11-26 09:27:56,431 - util.py:196:DEBUG: Run cmd: /usr/sbin/groupdel mockbuild
>2007-11-26 09:27:56,431 - util.py:202:DEBUG: Executing timeout(0): /usr/sbin/groupdel mockbuild
>2007-11-26 09:27:56,432 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:27:56,433 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:56,433 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 03:27:56,433 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,442 - util.py:218:DEBUG: groupdel: group mockbuild does not exist
>2007-11-26 09:27:56,442 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,442 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:27:56,442 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, '/usr/sbin/groupadd -g 494 mockbuild', ''), {})
>2007-11-26 09:27:56,443 - trace_decorator.py:20:DEBUG: ENTER: do(('/usr/sbin/groupadd -g 494 mockbuild', '/var/lib/mock/ldap-i386/root', 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,443 - util.py:196:DEBUG: Run cmd: /usr/sbin/groupadd -g 494 mockbuild
>2007-11-26 09:27:56,443 - util.py:202:DEBUG: Executing timeout(0): /usr/sbin/groupadd -g 494 mockbuild
>2007-11-26 09:27:56,444 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:27:56,445 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:56,445 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 03:27:56,445 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,459 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,459 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:27:56,459 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, '/usr/sbin/useradd -m -u 500 -g 494 -d /builddir -n mockbuild', ''), {})
>2007-11-26 09:27:56,459 - trace_decorator.py:20:DEBUG: ENTER: do(('/usr/sbin/useradd -m -u 500 -g 494 -d /builddir -n mockbuild', '/var/lib/mock/ldap-i386/root', 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,460 - util.py:196:DEBUG: Run cmd: /usr/sbin/useradd -m -u 500 -g 494 -d /builddir -n mockbuild
>2007-11-26 09:27:56,460 - util.py:202:DEBUG: Executing timeout(0): /usr/sbin/useradd -m -u 500 -g 494 -d /builddir -n mockbuild
>2007-11-26 09:27:56,461 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:27:56,462 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:56,462 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 03:27:56,462 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,477 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,477 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:27:56,477 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, "perl -p -i -e 's/^(mockbuild:)!!/$1/;' /etc/passwd", ''), {'raiseExc': True})
>2007-11-26 09:27:56,477 - trace_decorator.py:20:DEBUG: ENTER: do(("perl -p -i -e 's/^(mockbuild:)!!/$1/;' /etc/passwd", '/var/lib/mock/ldap-i386/root', 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,478 - util.py:196:DEBUG: Run cmd: perl -p -i -e 's/^(mockbuild:)!!/$1/;' /etc/passwd
>2007-11-26 09:27:56,478 - util.py:202:DEBUG: Executing timeout(0): perl -p -i -e 's/^(mockbuild:)!!/$1/;' /etc/passwd
>2007-11-26 09:27:56,479 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:27:56,480 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:56,480 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 03:27:56,480 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,492 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,492 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:27:56,492 - trace_decorator.py:30:DEBUG: LEAVE _makeBuildUser --> None
>
>2007-11-26 09:27:56,492 - trace_decorator.py:20:DEBUG: ENTER: _buildDirSetup((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:27:56,493 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,493 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,493 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:56,493 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,493 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,493 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:56,494 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:56,494 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:27:56,494 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/RPMS',), {})
>2007-11-26 09:27:56,494 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/RPMS
>2007-11-26 09:27:56,494 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/RPMS
>2007-11-26 09:27:56,495 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,495 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/SRPMS',), {})
>2007-11-26 09:27:56,495 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/SRPMS
>2007-11-26 09:27:56,495 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/SRPMS
>2007-11-26 09:27:56,495 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,495 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/SOURCES',), {})
>2007-11-26 09:27:56,496 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/SOURCES
>2007-11-26 09:27:56,496 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/SOURCES
>2007-11-26 09:27:56,496 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,496 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/SPECS',), {})
>2007-11-26 09:27:56,496 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/SPECS
>2007-11-26 09:27:56,497 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/SPECS
>2007-11-26 09:27:56,497 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,497 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/BUILD',), {})
>2007-11-26 09:27:56,497 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/BUILD
>2007-11-26 09:27:56,497 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/BUILD
>2007-11-26 09:27:56,498 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,498 - trace_decorator.py:20:DEBUG: ENTER: mkdirIfAbsent(('/var/lib/mock/ldap-i386/root//builddir/build/originals',), {})
>2007-11-26 09:27:56,498 - util.py:38:DEBUG: ensuring that dir exists: /var/lib/mock/ldap-i386/root//builddir/build/originals
>2007-11-26 09:27:56,498 - util.py:41:DEBUG: creating dir: /var/lib/mock/ldap-i386/root//builddir/build/originals
>2007-11-26 09:27:56,498 - trace_decorator.py:30:DEBUG: LEAVE mkdirIfAbsent --> None
>
>2007-11-26 09:27:56,499 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,499 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,499 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:56,499 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 09:27:56,499 - trace_decorator.py:30:DEBUG: LEAVE _buildDirSetup --> None
>
>2007-11-26 09:27:56,499 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'postinit'), {})
>2007-11-26 09:27:56,500 - trace_decorator.py:20:DEBUG: ENTER: _rootCachePostInitHook((<root_cache.RootCache object at 0x892490>,), {})
>2007-11-26 09:27:56,500 - trace_decorator.py:30:DEBUG: LEAVE _rootCachePostInitHook --> None
>
>2007-11-26 09:27:56,500 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:56,500 - trace_decorator.py:30:DEBUG: LEAVE init --> None
>
>2007-11-26 09:27:56,500 - trace_decorator.py:20:DEBUG: ENTER: build((<mock.backend.Root object at 0x882890>, 'cyrus-sasl-2.1.22-9.fc9.src.rpm', 0), {})
>2007-11-26 09:27:56,500 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'earlyprebuild'), {})
>2007-11-26 09:27:56,500 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:56,501 - trace_decorator.py:20:DEBUG: ENTER: _mountall((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:27:56,501 - backend.py:424:INFO: mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,501 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,501 - util.py:196:DEBUG: Run cmd: mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,501 - util.py:202:DEBUG: Executing timeout(0): mount -n -t proc   mock_chroot_proc   /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:27:56,503 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,503 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,503 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,504 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,521 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,522 - backend.py:424:INFO: mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,522 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,522 - util.py:196:DEBUG: Run cmd: mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,522 - util.py:202:DEBUG: Executing timeout(0): mount -n -t devpts mock_chroot_devpts /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:27:56,524 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,524 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,524 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,525 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,541 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,541 - backend.py:424:INFO: mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,541 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,542 - util.py:196:DEBUG: Run cmd: mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,542 - util.py:202:DEBUG: Executing timeout(0): mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:27:56,543 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,544 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,544 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,544 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,563 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,564 - backend.py:424:INFO: mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,564 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,564 - util.py:196:DEBUG: Run cmd: mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,564 - util.py:202:DEBUG: Executing timeout(0): mount -n --bind /var/lib/mock/cache/ldap-i386/ccache/  /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:27:56,565 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,566 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,566 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,566 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,576 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,576 - backend.py:424:INFO: mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,576 - trace_decorator.py:20:DEBUG: ENTER: do(('mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum', None, 0, True, 0, None, None, None), {})
>2007-11-26 09:27:56,577 - util.py:196:DEBUG: Run cmd: mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,577 - util.py:202:DEBUG: Executing timeout(0): mount -n --bind /var/lib/mock/cache/ldap-i386/yum_cache/  /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:27:56,578 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:56,578 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:56,579 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:56,579 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:56,587 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:56,587 - trace_decorator.py:30:DEBUG: LEAVE _mountall --> None
>
>2007-11-26 09:27:56,587 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,588 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,588 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:56,588 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,588 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,588 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:56,588 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:56,588 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:27:56,589 - trace_decorator.py:20:DEBUG: ENTER: state((<mock.backend.Root object at 0x882890>, 'setup'), {})
>2007-11-26 09:27:56,589 - trace_decorator.py:30:DEBUG: LEAVE state --> setup
>
>2007-11-26 09:27:56,589 - trace_decorator.py:20:DEBUG: ENTER: _copySrpmIntoChroot((<mock.backend.Root object at 0x882890>, 'cyrus-sasl-2.1.22-9.fc9.src.rpm'), {})
>2007-11-26 09:27:56,589 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,589 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,589 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:56,590 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 500, -1), {})
>2007-11-26 09:27:56,590 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:56,590 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:56,590 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:56,590 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:27:57,211 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,211 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,212 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:57,212 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 09:27:57,212 - trace_decorator.py:30:DEBUG: LEAVE _copySrpmIntoChroot --> /builddir/build/originals/cyrus-sasl-2.1.22-9.fc9.src.rpm
>
>2007-11-26 09:27:57,212 - trace_decorator.py:20:DEBUG: ENTER: do(('rpm -Uvh --nodeps /builddir/build/originals/cyrus-sasl-2.1.22-9.fc9.src.rpm', '/var/lib/mock/ldap-i386/root', 0, True, 0, <mock.uid.uidManager object at 0x882910>, 500, 494), {})
>2007-11-26 09:27:57,213 - util.py:196:DEBUG: Run cmd: rpm -Uvh --nodeps /builddir/build/originals/cyrus-sasl-2.1.22-9.fc9.src.rpm
>2007-11-26 09:27:57,213 - util.py:202:DEBUG: Executing timeout(0): rpm -Uvh --nodeps /builddir/build/originals/cyrus-sasl-2.1.22-9.fc9.src.rpm
>2007-11-26 09:27:57,215 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', <mock.uid.uidManager object at 0x882910>), {})
>2007-11-26 09:27:57,221 - util.py:162:DEBUG: elevate privs to run chroot
>2007-11-26 09:27:57,222 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:27:57,222 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,222 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:57,223 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:27:57,223 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,224 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:57,224 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:57,224 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:27:57,224 - util.py:167:DEBUG: back to other privs
>2007-11-26 03:27:57,225 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,225 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,225 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:27:57,226 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 03:27:57,226 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:57,226 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((<mock.uid.uidManager object at 0x882910>, 500, 494), {})
>2007-11-26 03:27:57,226 - util.py:173:DEBUG: about to drop privs
>2007-11-26 03:27:57,227 - trace_decorator.py:20:DEBUG: ENTER: dropPrivsForever((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,227 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,227 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:27:57,227 - trace_decorator.py:30:DEBUG: LEAVE dropPrivsForever --> None
>
>2007-11-26 03:27:57,228 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:57,498 - util.py:218:DEBUG: cyrus-sasl                  warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,499 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: ######warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,500 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: ############################################
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,501 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: user kojibuilder does not exist - using root
>2007-11-26 09:27:57,502 - util.py:218:DEBUG: warning: group kojibuilder does not exist - using root
>2007-11-26 09:27:57,503 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:27:57,504 - backend.py:345:INFO: about to drop to unpriv mode.
>2007-11-26 09:27:57,505 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', <mock.uid.uidManager object at 0x882910>), {})
>2007-11-26 09:27:57,506 - util.py:162:DEBUG: elevate privs to run chroot
>2007-11-26 09:27:57,506 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:27:57,506 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,507 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:57,507 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:27:57,507 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:57,507 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:57,507 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:57,507 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:27:57,507 - util.py:167:DEBUG: back to other privs
>2007-11-26 03:27:57,508 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,508 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,508 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:27:57,508 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 03:27:57,508 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:27:57,508 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((<mock.uid.uidManager object at 0x882910>, 500, 494), {})
>2007-11-26 03:27:57,508 - util.py:173:DEBUG: about to drop privs
>2007-11-26 03:27:57,508 - trace_decorator.py:20:DEBUG: ENTER: dropPrivsForever((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,509 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:27:57,509 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:27:57,509 - trace_decorator.py:30:DEBUG: LEAVE dropPrivsForever --> None
>
>2007-11-26 03:27:57,509 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:27:59,932 - trace_decorator.py:20:DEBUG: ENTER: installSrpmDeps((<mock.backend.Root object at 0x882890>, '/var/lib/mock/ldap-i386/root//builddir/build/SRPMS/cyrus-sasl-2.1.22-9.fc9.src.rpm'), {})
>2007-11-26 09:27:59,932 - trace_decorator.py:20:DEBUG: ENTER: dropPrivsTemp((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:59,932 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:59,932 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:27:59,932 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 500, 500), {})
>2007-11-26 09:27:59,933 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:59,933 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:59,933 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:27:59,933 - trace_decorator.py:30:DEBUG: LEAVE dropPrivsTemp --> None
>
>2007-11-26 09:27:59,933 - trace_decorator.py:20:DEBUG: ENTER: yieldSrpmHeaders((('/var/lib/mock/ldap-i386/root//builddir/build/SRPMS/cyrus-sasl-2.1.22-9.fc9.src.rpm',), 0), {})
>2007-11-26 09:27:59,933 - trace_decorator.py:30:DEBUG: LEAVE yieldSrpmHeaders --> <generator object at 0x88dc68>
>
>2007-11-26 09:27:59,934 - trace_decorator.py:20:DEBUG: ENTER: requiresTextFromHdr((<rpm.hdr object at 0x88b870>,), {})
>2007-11-26 09:27:59,934 - trace_decorator.py:30:DEBUG: LEAVE requiresTextFromHdr --> ['mysql-devel', 'zlib-devel', 'autoconf', 'pkgconfig', 'openssl-devel', 'automake', 'krb5-devel >= 1.2.2', 'libtool', 'postgresql-devel', 'openldap-devel', 'groff', 'gdbm-devel', 'pam-devel']
>
>2007-11-26 09:27:59,934 - trace_decorator.py:20:DEBUG: ENTER: getAddtlReqs((<rpm.hdr object at 0x88b870>, {}), {})
>2007-11-26 09:27:59,934 - trace_decorator.py:20:DEBUG: ENTER: getNEVRA((<rpm.hdr object at 0x88b870>,), {})
>2007-11-26 09:27:59,934 - trace_decorator.py:30:DEBUG: LEAVE getNEVRA --> ('cyrus-sasl', 0, '2.1.22', '9.fc9', 'i386')
>
>2007-11-26 09:27:59,935 - trace_decorator.py:30:DEBUG: LEAVE getAddtlReqs --> []
>
>2007-11-26 09:27:59,935 - trace_decorator.py:20:DEBUG: ENTER: uniqReqs((['mysql-devel', 'zlib-devel', 'autoconf', 'pkgconfig', 'openssl-devel', 'automake', 'krb5-devel >= 1.2.2', 'libtool', 'postgresql-devel', 'openldap-devel', 'groff', 'gdbm-devel', 'pam-devel'], []), {})
>2007-11-26 09:27:59,935 - trace_decorator.py:30:DEBUG: LEAVE uniqReqs --> ['mysql-devel', 'zlib-devel', 'groff', 'pkgconfig', 'openssl-devel', 'automake', 'krb5-devel >= 1.2.2', 'libtool', 'postgresql-devel', 'openldap-devel', 'autoconf', 'gdbm-devel', 'pam-devel']
>
>2007-11-26 09:27:59,935 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:59,935 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:27:59,935 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:27:59,935 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 09:27:59,936 - trace_decorator.py:20:DEBUG: ENTER: _yum((<mock.backend.Root object at 0x882890>, "resolvedep ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'", 1), {})
>2007-11-26 09:27:59,936 - backend.py:439:INFO: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root resolvedep ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:27:59,936 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'preyum'), {})
>2007-11-26 09:27:59,936 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePreYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:27:59,936 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePreYumHook --> None
>
>2007-11-26 09:27:59,936 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:27:59,936 - trace_decorator.py:20:DEBUG: ENTER: do(("/usr/bin/yum --installroot /var/lib/mock/ldap-i386/root resolvedep ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'", None, 0, True, 1, None, None, None), {})
>2007-11-26 09:27:59,936 - util.py:196:DEBUG: Run cmd: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root resolvedep ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:27:59,937 - util.py:202:DEBUG: Executing timeout(0): /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root resolvedep ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:27:59,938 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:27:59,939 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:27:59,939 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:27:59,939 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:28:00,974 - util.py:218:DEBUG: 0:ccache-2.4-11.fc8.i386
>2007-11-26 09:28:00,974 - util.py:218:DEBUG: 0:mysql-devel-5.0.45-4.fc8.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:zlib-devel-1.2.3-16.fc9.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:groff-1.18.1.4-10.fc8.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 1:pkgconfig-0.22-4.fc9.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:openssl-devel-0.9.8b-17.fc8.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:automake-1.10-7.noarch
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:krb5-devel-1.6.3-1.fc9.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:libtool-1.5.24-3.fc8.i386
>2007-11-26 09:28:00,975 - util.py:218:DEBUG: 0:postgresql-devel-8.2.5-1.fc8.i386
>2007-11-26 09:28:00,976 - util.py:218:DEBUG: 0:openldap-devel-2.4.6-0.fc9.preview.i386
>2007-11-26 09:28:00,976 - util.py:218:DEBUG: 0:autoconf-2.61-10.fc9.noarch
>2007-11-26 09:28:00,976 - util.py:218:DEBUG: 0:gdbm-devel-1.8.0-27.fc7.i386
>2007-11-26 09:28:00,976 - util.py:218:DEBUG: 0:pam-devel-0.99.8.1-11.fc9.i386
>2007-11-26 09:28:00,976 - trace_decorator.py:30:DEBUG: LEAVE do --> 0:ccache-2.4-11.fc8.i386
>0:mysql-devel-5.0.45-4.fc8.i386
>0:zlib-devel-1.2.3-16.fc9.i386
>0:groff-1.18.1.4-10.fc8.i386
>1:pkgconfig-0.22-4.fc9.i386
>0:openssl-devel-0.9.8b-17.fc8.i386
>0:automake-1.10-7.noarch
>0:krb5-devel-1.6.3-1.fc9.i386
>0:libtool-1.5.24-3.fc8.i386
>0:postgresql-devel-8.2.5-1.fc8.i386
>0:openldap-devel-2.4.6-0.fc9.preview.i386
>0:autoconf-2.61-10.fc9.noarch
>0:gdbm-devel-1.8.0-27.fc7.i386
>0:pam-devel-0.99.8.1-11.fc9.i386
>
>
>2007-11-26 09:28:00,976 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'postyum'), {})
>2007-11-26 09:28:00,976 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePostYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:28:00,977 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePostYumHook --> None
>
>2007-11-26 09:28:00,977 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:28:00,977 - trace_decorator.py:30:DEBUG: LEAVE _yum --> 0:ccache-2.4-11.fc8.i386
>0:mysql-devel-5.0.45-4.fc8.i386
>0:zlib-devel-1.2.3-16.fc9.i386
>0:groff-1.18.1.4-10.fc8.i386
>1:pkgconfig-0.22-4.fc9.i386
>0:openssl-devel-0.9.8b-17.fc8.i386
>0:automake-1.10-7.noarch
>0:krb5-devel-1.6.3-1.fc9.i386
>0:libtool-1.5.24-3.fc8.i386
>0:postgresql-devel-8.2.5-1.fc8.i386
>0:openldap-devel-2.4.6-0.fc9.preview.i386
>0:autoconf-2.61-10.fc9.noarch
>0:gdbm-devel-1.8.0-27.fc7.i386
>0:pam-devel-0.99.8.1-11.fc9.i386
>
>
>2007-11-26 09:28:00,977 - trace_decorator.py:20:DEBUG: ENTER: _yum((<mock.backend.Root object at 0x882890>, "install ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'", 1), {})
>2007-11-26 09:28:00,977 - backend.py:439:INFO: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root install ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:28:00,977 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'preyum'), {})
>2007-11-26 09:28:00,977 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePreYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:28:00,978 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePreYumHook --> None
>
>2007-11-26 09:28:00,978 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:28:00,978 - trace_decorator.py:20:DEBUG: ENTER: do(("/usr/bin/yum --installroot /var/lib/mock/ldap-i386/root install ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'", None, 0, True, 1, None, None, None), {})
>2007-11-26 09:28:00,978 - util.py:196:DEBUG: Run cmd: /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root install ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:28:00,978 - util.py:202:DEBUG: Executing timeout(0): /usr/bin/yum --installroot /var/lib/mock/ldap-i386/root install ccache 'mysql-devel' 'zlib-devel' 'groff' 'pkgconfig' 'openssl-devel' 'automake' 'krb5-devel >= 1.2.2' 'libtool' 'postgresql-devel' 'openldap-devel' 'autoconf' 'gdbm-devel' 'pam-devel'
>2007-11-26 09:28:00,980 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:28:00,980 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:28:00,980 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:28:00,980 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:28:29,492 - util.py:218:DEBUG: 
>2007-11-26 09:28:29,492 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  Package                 Arch       Version          Repository        Size 
>2007-11-26 09:28:29,493 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:28:29,493 - util.py:218:DEBUG: Installing:
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  ccache                  i386       2.4-11.fc8       fedora             52 k
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  gdbm-devel              i386       1.8.0-27.fc7     fedora             36 k
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  groff                   i386       1.18.1.4-10.fc8  fedora            1.9 M
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  libtool                 i386       1.5.24-3.fc8     fedora            684 k
>2007-11-26 09:28:29,493 - util.py:218:DEBUG:  mysql-devel             i386       5.0.45-4.fc8     fedora            2.4 M
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  openldap-devel          i386       2.4.6-0.fc9.preview  ldap              1.5 M
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  pam-devel               i386       0.99.8.1-11.fc9  fedora            186 k
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  postgresql-devel        i386       8.2.5-1.fc8      fedora            1.2 M
>2007-11-26 09:28:29,494 - util.py:218:DEBUG: Installing for dependencies:
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  MAKEDEV                 i386       3.23-1.2         fedora            135 k
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  autoconf                noarch     2.61-10.fc9      fedora            799 k
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  automake                noarch     1.10-7           fedora            514 k
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  cyrus-sasl-devel        i386       2.1.22-9.fc9     fedora            351 k
>2007-11-26 09:28:29,494 - util.py:218:DEBUG:  cyrus-sasl-lib          i386       2.1.22-9.fc9     fedora            1.1 M
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  device-mapper           i386       1.02.22-1.fc8    fedora            466 k
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  e2fsprogs               i386       1.40.2-10.fc8    fedora            1.0 M
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  e2fsprogs-devel         i386       1.40.2-10.fc8    fedora            635 k
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  ethtool                 i386       5-1.fc7          fedora             60 k
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  glib2                   i386       2.14.4-1.fc9     fedora            824 k
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  imake                   i386       1.0.2-5.fc8      fedora            312 k
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  initscripts             i386       8.60-1           fedora            1.6 M
>2007-11-26 09:28:29,495 - util.py:218:DEBUG:  iproute                 i386       2.6.23-1.fc9     fedora            826 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  iputils                 i386       20070202-5.fc8   fedora            126 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  keyutils-libs           i386       1.2-2.fc6        fedora             18 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  keyutils-libs-devel     i386       1.2-2.fc6        fedora             28 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  krb5-devel              i386       1.6.3-1.fc9      fedora            1.1 M
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  krb5-libs               i386       1.6.3-1.fc9      fedora            715 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  libidn                  i386       0.6.14-4         fedora            210 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  libselinux-devel        i386       2.0.42-1.fc9     fedora            155 k
>2007-11-26 09:28:29,496 - util.py:218:DEBUG:  libsepol-devel          i386       2.0.14-1.fc9     fedora            181 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  libsysfs                i386       2.1.0-1.fc7      fedora             48 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  libvolume_id            i386       116-3.fc8        fedora             53 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  m4                      i386       1.4.10-1.fc8     fedora            209 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  mingetty                i386       1.07-6           fedora             19 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  module-init-tools       i386       3.4-2.fc8        fedora            414 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  mysql                   i386       5.0.45-4.fc8     fedora            2.7 M
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  mysql-libs              i386       5.0.45-4.fc8     fedora            1.5 M
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  net-tools               i386       1.60-84.fc8      fedora            361 k
>2007-11-26 09:28:29,497 - util.py:218:DEBUG:  openldap                i386       2.4.6-0.fc9.preview  ldap              302 k
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  openssl                 i386       0.9.8b-17.fc8    fedora            1.4 M
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  openssl-devel           i386       0.9.8b-17.fc8    fedora            1.8 M
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  perl-DBI                i386       1.601-1.fc9      fedora            729 k
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  pkgconfig               i386       1:0.22-4.fc9     fedora             66 k
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  postgresql              i386       8.2.5-1.fc8      fedora            3.0 M
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  postgresql-libs         i386       8.2.5-1.fc8      fedora            197 k
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  procps                  i386       3.2.7-17.fc8     fedora            210 k
>2007-11-26 09:28:29,498 - util.py:218:DEBUG:  psmisc                  i386       22.5-2.fc8       fedora             71 k
>2007-11-26 09:28:29,499 - util.py:218:DEBUG:  rsyslog                 i386       1.19.10-1.fc9    fedora            201 k
>2007-11-26 09:28:29,499 - util.py:218:DEBUG:  sysvinit                i386       2.86-18          fedora            110 k
>2007-11-26 09:28:29,499 - util.py:218:DEBUG:  udev                    i386       116-3.fc8        fedora            327 k
>2007-11-26 09:28:29,499 - util.py:218:DEBUG:  zlib-devel              i386       1.2.3-16.fc9     fedora             42 k
>2007-11-26 09:28:29,499 - util.py:218:DEBUG: 
>2007-11-26 09:28:29,499 - util.py:218:DEBUG: Transaction Summary
>2007-11-26 09:28:29,499 - util.py:218:DEBUG: =============================================================================
>2007-11-26 09:28:29,499 - util.py:218:DEBUG: Install     50 Package(s)         
>2007-11-26 09:28:29,499 - util.py:218:DEBUG: Update       0 Package(s)         
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: Remove       0 Package(s)         
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: 
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: Total download size: 33 M
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: 
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: Installed: ccache.i386 0:2.4-11.fc8 gdbm-devel.i386 0:1.8.0-27.fc7 groff.i386 0:1.18.1.4-10.fc8 libtool.i386 0:1.5.24-3.fc8 mysql-devel.i386 0:5.0.45-4.fc8 openldap-devel.i386 0:2.4.6-0.fc9.preview pam-devel.i386 0:0.99.8.1-11.fc9 postgresql-devel.i386 0:8.2.5-1.fc8
>2007-11-26 09:28:29,500 - util.py:218:DEBUG: Dependency Installed: MAKEDEV.i386 0:3.23-1.2 autoconf.noarch 0:2.61-10.fc9 automake.noarch 0:1.10-7 cyrus-sasl-devel.i386 0:2.1.22-9.fc9 cyrus-sasl-lib.i386 0:2.1.22-9.fc9 device-mapper.i386 0:1.02.22-1.fc8 e2fsprogs.i386 0:1.40.2-10.fc8 e2fsprogs-devel.i386 0:1.40.2-10.fc8 ethtool.i386 0:5-1.fc7 glib2.i386 0:2.14.4-1.fc9 imake.i386 0:1.0.2-5.fc8 initscripts.i386 0:8.60-1 iproute.i386 0:2.6.23-1.fc9 iputils.i386 0:20070202-5.fc8 keyutils-libs.i386 0:1.2-2.fc6 keyutils-libs-devel.i386 0:1.2-2.fc6 krb5-devel.i386 0:1.6.3-1.fc9 krb5-libs.i386 0:1.6.3-1.fc9 libidn.i386 0:0.6.14-4 libselinux-devel.i386 0:2.0.42-1.fc9 libsepol-devel.i386 0:2.0.14-1.fc9 libsysfs.i386 0:2.1.0-1.fc7 libvolume_id.i386 0:116-3.fc8 m4.i386 0:1.4.10-1.fc8 mingetty.i386 0:1.07-6 module-init-tools.i386 0:3.4-2.fc8 mysql.i386 0:5.0.45-4.fc8 mysql-libs.i386 0:5.0.45-4.fc8 net-tools.i386 0:1.60-84.fc8 openldap.i386 0:2.4.6-0.fc9.preview openssl.i386 0:0.9.8b-17.fc8 openssl-devel.i386 0:0.9.8b-17.fc8 perl-DBI.i386 0:1.601-1.fc9 pkgconfig.i386 1:0.22-4.fc9 postgresql.i386 0:8.2.5-1.fc8 postgresql-libs.i386 0:8.2.5-1.fc8 procps.i386 0:3.2.7-17.fc8 psmisc.i386 0:22.5-2.fc8 rsyslog.i386 0:1.19.10-1.fc9 sysvinit.i386 0:2.86-18 udev.i386 0:116-3.fc8 zlib-devel.i386 0:1.2.3-16.fc9
>2007-11-26 09:28:29,501 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>=============================================================================
> Package                 Arch       Version          Repository        Size 
>=============================================================================
>Installing:
> ccache                  i386       2.4-11.fc8       fedora             52 k
> gdbm-devel              i386       1.8.0-27.fc7     fedora             36 k
> groff                   i386       1.18.1.4-10.fc8  fedora            1.9 M
> libtool                 i386       1.5.24-3.fc8     fedora            684 k
> mysql-devel             i386       5.0.45-4.fc8     fedora            2.4 M
> openldap-devel          i386       2.4.6-0.fc9.preview  ldap              1.5 M
> pam-devel               i386       0.99.8.1-11.fc9  fedora            186 k
> postgresql-devel        i386       8.2.5-1.fc8      fedora            1.2 M
>Installing for dependencies:
> MAKEDEV                 i386       3.23-1.2         fedora            135 k
> autoconf                noarch     2.61-10.fc9      fedora            799 k
> automake                noarch     1.10-7           fedora            514 k
> cyrus-sasl-devel        i386       2.1.22-9.fc9     fedora            351 k
> cyrus-sasl-lib          i386       2.1.22-9.fc9     fedora            1.1 M
> device-mapper           i386       1.02.22-1.fc8    fedora            466 k
> e2fsprogs               i386       1.40.2-10.fc8    fedora            1.0 M
> e2fsprogs-devel         i386       1.40.2-10.fc8    fedora            635 k
> ethtool                 i386       5-1.fc7          fedora             60 k
> glib2                   i386       2.14.4-1.fc9     fedora            824 k
> imake                   i386       1.0.2-5.fc8      fedora            312 k
> initscripts             i386       8.60-1           fedora            1.6 M
> iproute                 i386       2.6.23-1.fc9     fedora            826 k
> iputils                 i386       20070202-5.fc8   fedora            126 k
> keyutils-libs           i386       1.2-2.fc6        fedora             18 k
> keyutils-libs-devel     i386       1.2-2.fc6        fedora             28 k
> krb5-devel              i386       1.6.3-1.fc9      fedora            1.1 M
> krb5-libs               i386       1.6.3-1.fc9      fedora            715 k
> libidn                  i386       0.6.14-4         fedora            210 k
> libselinux-devel        i386       2.0.42-1.fc9     fedora            155 k
> libsepol-devel          i386       2.0.14-1.fc9     fedora            181 k
> libsysfs                i386       2.1.0-1.fc7      fedora             48 k
> libvolume_id            i386       116-3.fc8        fedora             53 k
> m4                      i386       1.4.10-1.fc8     fedora            209 k
> mingetty                i386       1.07-6           fedora             19 k
> module-init-tools       i386       3.4-2.fc8        fedora            414 k
> mysql                   i386       5.0.45-4.fc8     fedora            2.7 M
> mysql-libs              i386       5.0.45-4.fc8     fedora            1.5 M
> net-tools               i386       1.60-84.fc8      fedora            361 k
> openldap                i386       2.4.6-0.fc9.preview  ldap              302 k
> openssl                 i386       0.9.8b-17.fc8    fedora            1.4 M
> openssl-devel           i386       0.9.8b-17.fc8    fedora            1.8 M
> perl-DBI                i386       1.601-1.fc9      fedora            729 k
> pkgconfig               i386       1:0.22-4.fc9     fedora             66 k
> postgresql              i386       8.2.5-1.fc8      fedora            3.0 M
> postgresql-libs         i386       8.2.5-1.fc8      fedora            197 k
> procps                  i386       3.2.7-17.fc8     fedora            210 k
> psmisc                  i386       22.5-2.fc8       fedora             71 k
> rsyslog                 i386       1.19.10-1.fc9    fedora            201 k
> sysvinit                i386       2.86-18          fedora            110 k
> udev                    i386       116-3.fc8        fedora            327 k
> zlib-devel              i386       1.2.3-16.fc9     fedora             42 k
>
>Transaction Summary
>=============================================================================
>Install     50 Package(s)         
>Update       0 Package(s)         
>Remove       0 Package(s)         
>
>Total download size: 33 M
>
>Installed: ccache.i386 0:2.4-11.fc8 gdbm-devel.i386 0:1.8.0-27.fc7 groff.i386 0:1.18.1.4-10.fc8 libtool.i386 0:1.5.24-3.fc8 mysql-devel.i386 0:5.0.45-4.fc8 openldap-devel.i386 0:2.4.6-0.fc9.preview pam-devel.i386 0:0.99.8.1-11.fc9 postgresql-devel.i386 0:8.2.5-1.fc8
>Dependency Installed: MAKEDEV.i386 0:3.23-1.2 autoconf.noarch 0:2.61-10.fc9 automake.noarch 0:1.10-7 cyrus-sasl-devel.i386 0:2.1.22-9.fc9 cyrus-sasl-lib.i386 0:2.1.22-9.fc9 device-mapper.i386 0:1.02.22-1.fc8 e2fsprogs.i386 0:1.40.2-10.fc8 e2fsprogs-devel.i386 0:1.40.2-10.fc8 ethtool.i386 0:5-1.fc7 glib2.i386 0:2.14.4-1.fc9 imake.i386 0:1.0.2-5.fc8 initscripts.i386 0:8.60-1 iproute.i386 0:2.6.23-1.fc9 iputils.i386 0:20070202-5.fc8 keyutils-libs.i386 0:1.2-2.fc6 keyutils-libs-devel.i386 0:1.2-2.fc6 krb5-devel.i386 0:1.6.3-1.fc9 krb5-libs.i386 0:1.6.3-1.fc9 libidn.i386 0:0.6.14-4 libselinux-devel.i386 0:2.0.42-1.fc9 libsepol-devel.i386 0:2.0.14-1.fc9 libsysfs.i386 0:2.1.0-1.fc7 libvolume_id.i386 0:116-3.fc8 m4.i386 0:1.4.10-1.fc8 mingetty.i386 0:1.07-6 module-init-tools.i386 0:3.4-2.fc8 mysql.i386 0:5.0.45-4.fc8 mysql-libs.i386 0:5.0.45-4.fc8 net-tools.i386 0:1.60-84.fc8 openldap.i386 0:2.4.6-0.fc9.preview openssl.i386 0:0.9.8b-17.fc8 openssl-devel.i386 0:0.9.8b-17.fc8 perl-DBI.i386 0:1.601-1.fc9 pkgconfig.i386 1:0.22-4.fc9 postgresql.i386 0:8.2.5-1.fc8 postgresql-libs.i386 0:8.2.5-1.fc8 procps.i386 0:3.2.7-17.fc8 psmisc.i386 0:22.5-2.fc8 rsyslog.i386 0:1.19.10-1.fc9 sysvinit.i386 0:2.86-18 udev.i386 0:116-3.fc8 zlib-devel.i386 0:1.2.3-16.fc9
>
>
>2007-11-26 09:28:29,501 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'postyum'), {})
>2007-11-26 09:28:29,501 - trace_decorator.py:20:DEBUG: ENTER: _yumCachePostYumHook((<yum_cache.YumCache object at 0x886e90>,), {})
>2007-11-26 09:28:29,501 - trace_decorator.py:30:DEBUG: LEAVE _yumCachePostYumHook --> None
>
>2007-11-26 09:28:29,501 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:28:29,501 - trace_decorator.py:30:DEBUG: LEAVE _yum --> 
>=============================================================================
> Package                 Arch       Version          Repository        Size 
>=============================================================================
>Installing:
> ccache                  i386       2.4-11.fc8       fedora             52 k
> gdbm-devel              i386       1.8.0-27.fc7     fedora             36 k
> groff                   i386       1.18.1.4-10.fc8  fedora            1.9 M
> libtool                 i386       1.5.24-3.fc8     fedora            684 k
> mysql-devel             i386       5.0.45-4.fc8     fedora            2.4 M
> openldap-devel          i386       2.4.6-0.fc9.preview  ldap              1.5 M
> pam-devel               i386       0.99.8.1-11.fc9  fedora            186 k
> postgresql-devel        i386       8.2.5-1.fc8      fedora            1.2 M
>Installing for dependencies:
> MAKEDEV                 i386       3.23-1.2         fedora            135 k
> autoconf                noarch     2.61-10.fc9      fedora            799 k
> automake                noarch     1.10-7           fedora            514 k
> cyrus-sasl-devel        i386       2.1.22-9.fc9     fedora            351 k
> cyrus-sasl-lib          i386       2.1.22-9.fc9     fedora            1.1 M
> device-mapper           i386       1.02.22-1.fc8    fedora            466 k
> e2fsprogs               i386       1.40.2-10.fc8    fedora            1.0 M
> e2fsprogs-devel         i386       1.40.2-10.fc8    fedora            635 k
> ethtool                 i386       5-1.fc7          fedora             60 k
> glib2                   i386       2.14.4-1.fc9     fedora            824 k
> imake                   i386       1.0.2-5.fc8      fedora            312 k
> initscripts             i386       8.60-1           fedora            1.6 M
> iproute                 i386       2.6.23-1.fc9     fedora            826 k
> iputils                 i386       20070202-5.fc8   fedora            126 k
> keyutils-libs           i386       1.2-2.fc6        fedora             18 k
> keyutils-libs-devel     i386       1.2-2.fc6        fedora             28 k
> krb5-devel              i386       1.6.3-1.fc9      fedora            1.1 M
> krb5-libs               i386       1.6.3-1.fc9      fedora            715 k
> libidn                  i386       0.6.14-4         fedora            210 k
> libselinux-devel        i386       2.0.42-1.fc9     fedora            155 k
> libsepol-devel          i386       2.0.14-1.fc9     fedora            181 k
> libsysfs                i386       2.1.0-1.fc7      fedora             48 k
> libvolume_id            i386       116-3.fc8        fedora             53 k
> m4                      i386       1.4.10-1.fc8     fedora            209 k
> mingetty                i386       1.07-6           fedora             19 k
> module-init-tools       i386       3.4-2.fc8        fedora            414 k
> mysql                   i386       5.0.45-4.fc8     fedora            2.7 M
> mysql-libs              i386       5.0.45-4.fc8     fedora            1.5 M
> net-tools               i386       1.60-84.fc8      fedora            361 k
> openldap                i386       2.4.6-0.fc9.preview  ldap              302 k
> openssl                 i386       0.9.8b-17.fc8    fedora            1.4 M
> openssl-devel           i386       0.9.8b-17.fc8    fedora            1.8 M
> perl-DBI                i386       1.601-1.fc9      fedora            729 k
> pkgconfig               i386       1:0.22-4.fc9     fedora             66 k
> postgresql              i386       8.2.5-1.fc8      fedora            3.0 M
> postgresql-libs         i386       8.2.5-1.fc8      fedora            197 k
> procps                  i386       3.2.7-17.fc8     fedora            210 k
> psmisc                  i386       22.5-2.fc8       fedora             71 k
> rsyslog                 i386       1.19.10-1.fc9    fedora            201 k
> sysvinit                i386       2.86-18          fedora            110 k
> udev                    i386       116-3.fc8        fedora            327 k
> zlib-devel              i386       1.2.3-16.fc9     fedora             42 k
>
>Transaction Summary
>=============================================================================
>Install     50 Package(s)         
>Update       0 Package(s)         
>Remove       0 Package(s)         
>
>Total download size: 33 M
>
>Installed: ccache.i386 0:2.4-11.fc8 gdbm-devel.i386 0:1.8.0-27.fc7 groff.i386 0:1.18.1.4-10.fc8 libtool.i386 0:1.5.24-3.fc8 mysql-devel.i386 0:5.0.45-4.fc8 openldap-devel.i386 0:2.4.6-0.fc9.preview pam-devel.i386 0:0.99.8.1-11.fc9 postgresql-devel.i386 0:8.2.5-1.fc8
>Dependency Installed: MAKEDEV.i386 0:3.23-1.2 autoconf.noarch 0:2.61-10.fc9 automake.noarch 0:1.10-7 cyrus-sasl-devel.i386 0:2.1.22-9.fc9 cyrus-sasl-lib.i386 0:2.1.22-9.fc9 device-mapper.i386 0:1.02.22-1.fc8 e2fsprogs.i386 0:1.40.2-10.fc8 e2fsprogs-devel.i386 0:1.40.2-10.fc8 ethtool.i386 0:5-1.fc7 glib2.i386 0:2.14.4-1.fc9 imake.i386 0:1.0.2-5.fc8 initscripts.i386 0:8.60-1 iproute.i386 0:2.6.23-1.fc9 iputils.i386 0:20070202-5.fc8 keyutils-libs.i386 0:1.2-2.fc6 keyutils-libs-devel.i386 0:1.2-2.fc6 krb5-devel.i386 0:1.6.3-1.fc9 krb5-libs.i386 0:1.6.3-1.fc9 libidn.i386 0:0.6.14-4 libselinux-devel.i386 0:2.0.42-1.fc9 libsepol-devel.i386 0:2.0.14-1.fc9 libsysfs.i386 0:2.1.0-1.fc7 libvolume_id.i386 0:116-3.fc8 m4.i386 0:1.4.10-1.fc8 mingetty.i386 0:1.07-6 module-init-tools.i386 0:3.4-2.fc8 mysql.i386 0:5.0.45-4.fc8 mysql-libs.i386 0:5.0.45-4.fc8 net-tools.i386 0:1.60-84.fc8 openldap.i386 0:2.4.6-0.fc9.preview openssl.i386 0:0.9.8b-17.fc8 openssl-devel.i386 0:0.9.8b-17.fc8 perl-DBI.i386 0:1.601-1.fc9 pkgconfig.i386 1:0.22-4.fc9 postgresql.i386 0:8.2.5-1.fc8 postgresql-libs.i386 0:8.2.5-1.fc8 procps.i386 0:3.2.7-17.fc8 psmisc.i386 0:22.5-2.fc8 rsyslog.i386 0:1.19.10-1.fc9 sysvinit.i386 0:2.86-18 udev.i386 0:116-3.fc8 zlib-devel.i386 0:1.2.3-16.fc9
>
>
>2007-11-26 09:28:29,501 - trace_decorator.py:30:DEBUG: LEAVE installSrpmDeps --> None
>
>2007-11-26 09:28:29,502 - trace_decorator.py:20:DEBUG: ENTER: state((<mock.backend.Root object at 0x882890>, 'build'), {})
>2007-11-26 09:28:29,502 - trace_decorator.py:30:DEBUG: LEAVE state --> build
>
>2007-11-26 09:28:29,502 - trace_decorator.py:20:DEBUG: ENTER: _callHooks((<mock.backend.Root object at 0x882890>, 'prebuild'), {})
>2007-11-26 09:28:29,502 - trace_decorator.py:20:DEBUG: ENTER: _ccacheBuildHook((<ccache.CCache object at 0x886c90>,), {})
>2007-11-26 09:28:29,502 - trace_decorator.py:20:DEBUG: ENTER: doChroot((<mock.backend.Root object at 0x882890>, 'ccache -M 4G', ''), {})
>2007-11-26 09:28:29,503 - trace_decorator.py:20:DEBUG: ENTER: do(('ccache -M 4G', '/var/lib/mock/ldap-i386/root', 0, True, 0, None, None, None), {})
>2007-11-26 09:28:29,503 - util.py:196:DEBUG: Run cmd: ccache -M 4G
>2007-11-26 09:28:29,503 - util.py:202:DEBUG: Executing timeout(0): ccache -M 4G
>2007-11-26 09:28:29,504 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', None), {})
>2007-11-26 09:28:29,505 - trace_decorator.py:27:DEBUG: EXCEPTION: [Errno 1] Operation not permitted: '/var/lib/mock/ldap-i386/root'
>Traceback (most recent call last):
>  File "/usr/lib/python2.5/site-packages/mock/trace_decorator.py", line 24, in trace
>    result = f(*args, **kw)
>  File "/usr/lib/python2.5/site-packages/mock/util.py", line 165, in condChroot
>    os.chroot(chrootPath)
>OSError: [Errno 1] Operation not permitted: '/var/lib/mock/ldap-i386/root'
>2007-11-26 09:28:29,506 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> EXCEPTION RAISED
>
>2007-11-26 09:28:29,506 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:28:29,507 - trace_decorator.py:30:DEBUG: LEAVE doChroot --> 
>
>2007-11-26 09:28:29,507 - trace_decorator.py:30:DEBUG: LEAVE _ccacheBuildHook --> None
>
>2007-11-26 09:28:29,507 - trace_decorator.py:30:DEBUG: LEAVE _callHooks --> None
>
>2007-11-26 09:28:29,508 - trace_decorator.py:20:DEBUG: ENTER: condChroot(('/var/lib/mock/ldap-i386/root', <mock.uid.uidManager object at 0x882910>), {})
>2007-11-26 09:28:29,509 - util.py:162:DEBUG: elevate privs to run chroot
>2007-11-26 09:28:29,509 - trace_decorator.py:20:DEBUG: ENTER: becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:28:29,509 - trace_decorator.py:20:DEBUG: ENTER: _push((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:28:29,510 - trace_decorator.py:30:DEBUG: LEAVE _push --> None
>
>2007-11-26 09:28:29,510 - trace_decorator.py:20:DEBUG: ENTER: _becomeUser((<mock.uid.uidManager object at 0x882910>, 0, -1), {})
>2007-11-26 09:28:29,510 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:28:29,510 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:28:29,510 - trace_decorator.py:30:DEBUG: LEAVE _becomeUser --> None
>
>2007-11-26 09:28:29,510 - trace_decorator.py:30:DEBUG: LEAVE becomeUser --> None
>
>2007-11-26 09:28:29,510 - util.py:167:DEBUG: back to other privs
>2007-11-26 03:28:29,511 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:28:29,511 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:28:29,511 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:28:29,511 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 03:28:29,511 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 03:28:29,511 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((<mock.uid.uidManager object at 0x882910>, 500, 494), {})
>2007-11-26 03:28:29,511 - util.py:173:DEBUG: about to drop privs
>2007-11-26 03:28:29,511 - trace_decorator.py:20:DEBUG: ENTER: dropPrivsForever((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:28:29,512 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 03:28:29,512 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 03:28:29,512 - trace_decorator.py:30:DEBUG: LEAVE dropPrivsForever --> None
>
>2007-11-26 03:28:29,512 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,094 - trace_decorator.py:20:DEBUG: ENTER: restorePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:30:00,094 - trace_decorator.py:20:DEBUG: ENTER: _elevatePrivs((<mock.uid.uidManager object at 0x882910>,), {})
>2007-11-26 09:30:00,094 - trace_decorator.py:30:DEBUG: LEAVE _elevatePrivs --> None
>
>2007-11-26 09:30:00,094 - trace_decorator.py:30:DEBUG: LEAVE restorePrivs --> None
>
>2007-11-26 09:30:00,094 - trace_decorator.py:20:DEBUG: ENTER: _umountall((<mock.backend.Root object at 0x882890>,), {})
>2007-11-26 09:30:00,094 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:30:00,094 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/proc', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:30:00,095 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:30:00,095 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/proc
>2007-11-26 09:30:00,096 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:30:00,097 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:30:00,097 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:30:00,097 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,107 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:30:00,108 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:30:00,108 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/dev/pts', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:30:00,108 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:30:00,108 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/dev/pts
>2007-11-26 09:30:00,109 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:30:00,110 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:30:00,110 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:30:00,110 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,119 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:30:00,119 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:30:00,119 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/sys', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:30:00,119 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:30:00,120 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/sys
>2007-11-26 09:30:00,121 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:30:00,121 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:30:00,121 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:30:00,121 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,130 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:30:00,130 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:30:00,130 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/tmp/ccache', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:30:00,130 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:30:00,130 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/tmp/ccache
>2007-11-26 09:30:00,132 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:30:00,132 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:30:00,133 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:30:00,133 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,142 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:30:00,142 - backend.py:431:INFO: umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:30:00,142 - trace_decorator.py:20:DEBUG: ENTER: do(('umount -n /var/lib/mock/ldap-i386/root/var/cache/yum', None, 0, 0, 0, None, None, None), {})
>2007-11-26 09:30:00,142 - util.py:196:DEBUG: Run cmd: umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:30:00,142 - util.py:202:DEBUG: Executing timeout(0): umount -n /var/lib/mock/ldap-i386/root/var/cache/yum
>2007-11-26 09:30:00,144 - trace_decorator.py:20:DEBUG: ENTER: condChroot((None, None), {})
>2007-11-26 09:30:00,144 - trace_decorator.py:30:DEBUG: LEAVE condChroot --> None
>
>2007-11-26 09:30:00,144 - trace_decorator.py:20:DEBUG: ENTER: condDropPrivs((None, None, None), {})
>2007-11-26 09:30:00,145 - trace_decorator.py:30:DEBUG: LEAVE condDropPrivs --> None
>
>2007-11-26 09:30:00,154 - trace_decorator.py:30:DEBUG: LEAVE do --> 
>
>2007-11-26 09:30:00,155 - trace_decorator.py:30:DEBUG: LEAVE _umountall --> None
>
>2007-11-26 09:30:00,155 - trace_decorator.py:27:DEBUG: EXCEPTION: Command(rpmbuild -bb --target i386 --nodeps //builddir/build/SPECS/cyrus-sasl.spec) failed. See logs for output.
>Traceback (most recent call last):
>  File "/usr/lib/python2.5/site-packages/mock/trace_decorator.py", line 24, in trace
>    result = f(*args, **kw)
>  File "/usr/lib/python2.5/site-packages/mock/backend.py", line 375, in build
>    logger=self.build_log, timeout=timeout,
>  File "<string>", line 1, in <lambda>
>  File "/usr/lib/python2.5/site-packages/mock/trace_decorator.py", line 24, in trace
>    result = f(*args, **kw)
>  File "/usr/lib/python2.5/site-packages/mock/util.py", line 244, in do
>    raise mock.exception.Error, "Command(%s) failed. See logs for output." % command
>Error: Command(rpmbuild -bb --target i386 --nodeps //builddir/build/SPECS/cyrus-sasl.spec) failed. See logs for output.
>2007-11-26 09:30:00,156 - trace_decorator.py:30:DEBUG: LEAVE build --> EXCEPTION RAISED
>
>2007-11-26 09:30:00,157 - trace_decorator.py:20:DEBUG: ENTER: orphansKill(('/var/lib/mock/ldap-i386/root',), {})
>2007-11-26 09:30:00,168 - trace_decorator.py:30:DEBUG: LEAVE orphansKill --> None
>

Actions: View

Attachments on bug 399261: 268681 | 268691