Bug 20059

Here is the log:


TesterTop3 telepathy-gabble-0.7.20 $ make -j1 check CHECK_TWISTED_VERBOSE=1 TWISTED_TESTS=vcard/test-vcard-race.pyMaking check in docs
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/docs'
make[1]: Nothing to be done for `check'.
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/docs'
Making check in tools
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tools'
make[1]: Nothing to be done for `check'.
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tools'
Making check in extensions
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/extensions'
make  check-am
make[2]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/extensions'
make[2]: Nothing to be done for `check-am'.
make[2]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/extensions'
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/extensions'
Making check in lib
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib'
Making check in gibber
make[2]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make  check-am
make[3]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make  check-local
make[4]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make[4]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make[3]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make[2]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make[2]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib'
make[2]: Nothing to be done for `check-am'.
make[2]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib'
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib'
Making check in src
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
make  check-am
make[2]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
make -C ../lib/gibber libgibber.la
make[3]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
make[3]: `libgibber.la' is up to date.
make[3]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/lib/gibber'
/bin/sh ../libtool --tag=CC --mode=link i686-pc-linux-gnu-gcc -std=gnu99 -Wall -Wdeclaration-after-statement -Wshadow -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -I.. -I.. -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include   -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include   -I/usr/include/loudmouth-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -rdynamic -I/usr/include/telepathy-1.0 -I/usr/include/dbus-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/lib/dbus-1.0/include -I ../lib -I ../lib -O2 -march=prescott -pipe  -Wl,-O1 -o telepathy-gabble  main.o libgabble-convenience.la ../lib/gibber/libgibber.la -ldbus-glib-1 -ldbus-1 -lgobject-2.0 -lglib-2.0   -lgobject-2.0 -lglib-2.0   -lloudmouth-1 -lidn -lglib-2.0   -ltelepathy-glib   
i686-pc-linux-gnu-gcc -std=gnu99 -Wall -Wdeclaration-after-statement -Wshadow -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -I.. -I.. -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/loudmouth-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -rdynamic -I/usr/include/telepathy-1.0 -I/usr/include/dbus-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/lib/dbus-1.0/include -I ../lib -I ../lib -O2 -march=prescott -pipe -Wl,-O1 -o telepathy-gabble main.o  ./.libs/libgabble-convenience.a ../lib/gibber/.libs/libgibber.a /usr/lib/libdbus-glib-1.so /usr/lib/libdbus-1.so /usr/lib/libgobject-2.0.so /usr/lib/libloudmouth-1.so /usr/lib/libidn.so /usr/lib/libglib-2.0.so /usr/lib/libtelepathy-glib.so  
/bin/sh ../libtool --tag=CC --mode=link i686-pc-linux-gnu-gcc -std=gnu99 -Wall -Wdeclaration-after-statement -Wshadow -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -I.. -I.. -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include   -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include   -I/usr/include/loudmouth-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -rdynamic -I/usr/include/telepathy-1.0 -I/usr/include/dbus-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/lib/dbus-1.0/include -I ../lib -I ../lib -O2 -march=prescott -pipe  -Wl,-O1 -o write-mgr-file  write-mgr-file.o libgabble-convenience.la ../lib/gibber/libgibber.la -ldbus-glib-1 -ldbus-1 -lgobject-2.0 -lglib-2.0   -lgobject-2.0 -lglib-2.0   -lloudmouth-1 -lidn -lglib-2.0   -ltelepathy-glib   
i686-pc-linux-gnu-gcc -std=gnu99 -Wall -Wdeclaration-after-statement -Wshadow -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -I.. -I.. -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/loudmouth-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -rdynamic -I/usr/include/telepathy-1.0 -I/usr/include/dbus-1.0 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/lib/dbus-1.0/include -I ../lib -I ../lib -O2 -march=prescott -pipe -Wl,-O1 -o write-mgr-file write-mgr-file.o  ./.libs/libgabble-convenience.a ../lib/gibber/.libs/libgibber.a /usr/lib/libdbus-glib-1.so /usr/lib/libdbus-1.so /usr/lib/libgobject-2.0.so /usr/lib/libloudmouth-1.so /usr/lib/libidn.so /usr/lib/libglib-2.0.so /usr/lib/libtelepathy-glib.so  
make  check-local
make[3]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
make[3]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
make[2]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/src'
Making check in data
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/data'
make[1]: Nothing to be done for `check'.
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/data'
Making check in m4
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/m4'
make[1]: Nothing to be done for `check'.
make[1]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/m4'
Making check in tests
make[1]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests'
Making check in twisted
make[2]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted'
make  check-recursive
make[3]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted'
Making check in tools
make[4]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make  check-am
make[5]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make[5]: Nothing to be done for `check-am'.
make[5]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make[4]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make[4]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted'
make  check-TESTS check-local
make[5]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted'
make -C tools
make[6]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make  all-am
make[7]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make[7]: Nothing to be done for `all-am'.
make[7]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
make[6]: Leaving directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted/tools'
rm -f tools/core
rm -f tools/gabble-testing.log
if test -n "$GABBLE_TEST_REFDBG"; then \
	  sleep=6; \
        else \
	  sleep=0; \
	fi; \
	sh ./tools/with-session-bus.sh \
		--sleep=$sleep \
		--config-file=tools/tmp-session-bus.conf \
		-- make check-TESTS \
		TESTS="vcard/test-vcard-race.py" \
		TESTS_ENVIRONMENT="PYTHONPATH=/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted:/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted python2.5"
Temporary bus daemon is unix:abstract=/tmp/dbus-KHFtErcCVz,guid=3c4d9d8499292613f51a36994992b9f7
Temporary bus daemon PID is 20654
make[6]: Entering directory `/var/tmp/portage/net-voip/telepathy-gabble-0.7.20/work/telepathy-gabble-0.7.20/tests/twisted'
got event:
- type: dbus-signal
- type dbus-signal
- args: [1L, 1L]
- interface: 'org.freedesktop.Telepathy.Connection'
- path: '/Connection/gabble/jabber/test_40localhost_2fResource'
- signal: 'StatusChanged'
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'get'
- query: <query xmlns='jabber:iq:auth'> <username>test</username>
</query>
- query_name: u'query'
- query_ns: u'jabber:iq:auth'
- stanza: <iq xmlns='jabber:client' type='get' id='32804573483'> <query xmlns='jabber:iq:auth'> <username>test</username>
</query>
</iq>
- to: None
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'set'
- query: <query xmlns='jabber:iq:auth'> <username>test</username>
 <digest>e71547e22c244e071cbb7e1fae1fab5c4907776a</digest>
 <resource>Resource</resource>
</query>
- query_name: u'query'
- query_ns: u'jabber:iq:auth'
- stanza: <iq xmlns='jabber:client' type='set' id='34950576132'> <query xmlns='jabber:iq:auth'> <username>test</username>
 <digest>e71547e22c244e071cbb7e1fae1fab5c4907776a</digest>
 <resource>Resource</resource>
</query>
</iq>
- to: None
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-authenticated
- type stream-authenticated
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'get'
- query: <query xmlns='http://jabber.org/protocol/disco#info'/>
- query_name: u'query'
- query_ns: u'http://jabber.org/protocol/disco#info'
- stanza: <iq xmlns='jabber:client' to='localhost' type='get' id='39140580329'> <query xmlns='http://jabber.org/protocol/disco#info'/>
</iq>
- to: u'localhost'
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-presence
- type stream-presence
- presence_type: None
- stanza: <presence xmlns='jabber:client' id='41399582075'> <x xmlns='vcard-temp:x:update'/>
 <c xmlns='http://jabber.org/protocol/caps' node='http://telepathy.freedesktop.org/caps' hash='sha-1' ver='vRZ6i9Nj4/q1+QQ99Di3a88ncFY='/>
</presence>
- to: None
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: dbus-signal
- type dbus-signal
- args: [{1L: (0L, {u'available': {}})}]
- interface: 'org.freedesktop.Telepathy.Connection.Interface.Presence'
- path: '/Connection/gabble/jabber/test_40localhost_2fResource'
- signal: 'PresenceUpdate'
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: dbus-signal
- type dbus-signal
- args: [{1L: (2L, u'available', u'')}]
- interface: 'org.freedesktop.Telepathy.Connection.Interface.SimplePresence'
- path: '/Connection/gabble/jabber/test_40localhost_2fResource'
- signal: 'PresencesChanged'
trying <function expect_connected at 0xa2e9ae4>
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: dbus-signal
- type dbus-signal
- args: [0L, 1L]
- interface: 'org.freedesktop.Telepathy.Connection'
- path: '/Connection/gabble/jabber/test_40localhost_2fResource'
- signal: 'StatusChanged'
trying <function expect_connected at 0xa2e9ae4>
event handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'get'
- query: <query xmlns='jabber:iq:roster'/>
- query_name: u'query'
- query_ns: u'jabber:iq:roster'
- stanza: <iq xmlns='jabber:client' type='get' id='41131582310'> <query xmlns='jabber:iq:roster'/>
</iq>
- to: None
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'get'
- query: <query xmlns='http://jabber.org/protocol/disco#items'/>
- query_name: u'query'
- query_ns: u'http://jabber.org/protocol/disco#items'
- stanza: <iq xmlns='jabber:client' to='localhost' type='get' id='41244582430'> <query xmlns='http://jabber.org/protocol/disco#items'/>
</iq>
- to: u'localhost'
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'set'
- query: <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://laptop.org/xmpp/activities'> <item> <activities xmlns='http://laptop.org/xmpp/activities'/>
</item>
</publish>
</pubsub>
- query_name: u'pubsub'
- query_ns: u'http://jabber.org/protocol/pubsub'
- stanza: <iq xmlns='jabber:client' type='set' id='43116584292'> <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://laptop.org/xmpp/activities'> <item> <activities xmlns='http://laptop.org/xmpp/activities'/>
</item>
</publish>
</pubsub>
</iq>
- to: None
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'set'
- query: <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://laptop.org/xmpp/activity-properties'> <item> <activities xmlns='http://laptop.org/xmpp/activity-properties'/>
</item>
</publish>
</pubsub>
- query_name: u'pubsub'
- query_ns: u'http://jabber.org/protocol/pubsub'
- stanza: <iq xmlns='jabber:client' type='set' id='43229584404'> <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://laptop.org/xmpp/activity-properties'> <item> <activities xmlns='http://laptop.org/xmpp/activity-properties'/>
</item>
</publish>
</pubsub>
</iq>
- to: None
trying <function expect_get_vcard at 0xa2e9bfc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'get'
- query: <vCard xmlns='vcard-temp'/>
- query_name: u'vCard'
- query_ns: u'vcard-temp'
- stanza: <iq xmlns='jabber:client' type='get' id='43037583710'> <vCard xmlns='vcard-temp'/>
</iq>
- to: None
trying <function expect_get_vcard at 0xa2e9bfc>
event handled

got event:
- type: dbus-return
- type dbus-return
- method: 'GetSelfHandle'
- value: (1L,)
trying <function expect_got_self_handle at 0xa2e9c6c>
event handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'set'
- query: <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://jabber.org/protocol/nick'> <item> <nick xmlns='http://jabber.org/protocol/nick'>Some Guy</nick>
</item>
</publish>
</pubsub>
- query_name: u'pubsub'
- query_ns: u'http://jabber.org/protocol/pubsub'
- stanza: <iq xmlns='jabber:client' type='set' id='39100629434'> <pubsub xmlns='http://jabber.org/protocol/pubsub'> <publish node='http://jabber.org/protocol/nick'> <item> <nick xmlns='http://jabber.org/protocol/nick'>Some Guy</nick>
</item>
</publish>
</pubsub>
</iq>
- to: None
trying <function expect_get_vcard_again at 0xa2e9cdc>
event not handled

got event:
- type: dbus-return
- type dbus-return
- method: 'SetAliases'
- value: ()
trying <function expect_get_vcard_again at 0xa2e9cdc>
event not handled

got event:
- type: dbus-signal
- type dbus-signal
- args: [1L, u'']
- interface: 'org.freedesktop.Telepathy.Connection.Interface.Avatars'
- path: '/Connection/gabble/jabber/test_40localhost_2fResource'
- signal: 'AvatarUpdated'
trying <function expect_get_vcard_again at 0xa2e9cdc>
event not handled

got event:
- type: stream-presence
- type stream-presence
- presence_type: None
- stanza: <presence xmlns='jabber:client' id='39136629980'> <x xmlns='vcard-temp:x:update'> <photo/>
</x>
 <c xmlns='http://jabber.org/protocol/caps' node='http://telepathy.freedesktop.org/caps' hash='sha-1' ver='vRZ6i9Nj4/q1+QQ99Di3a88ncFY='/>
</presence>
- to: None
trying <function expect_get_vcard_again at 0xa2e9cdc>
event not handled

got event:
- type: stream-iq
- type stream-iq
- iq_type: u'set'
- query: <vCard xmlns='vcard-temp'> <NICKNAME>Some Guy</NICKNAME>
</vCard>
- query_name: u'vCard'
- query_ns: u'vcard-temp'
- stanza: <iq xmlns='jabber:client' type='set' id='38945629782'> <vCard xmlns='vcard-temp'> <NICKNAME>Some Guy</NICKNAME>
</vCard>
</iq>
- to: None
trying <function expect_get_vcard_again at 0xa2e9cdc>
event not handled



timed out waiting for events
<function expect_get_vcard_again at 0xa2e9cdc>
FAIL: vcard/test-vcard-race.py