Bug 23168

Created attachment 28386 [details]
build-0.7.31.log

Created attachment 28387 [details]
build-0.7.30.log

Traceback (most recent call last):
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.30/work/telepathy-gabble-0.7.30/tests/twisted/gabbletest.py", line 381, in exec_test_deferred
    f(queue, bus, conn, stream)
  File "./tubes/offer-muc-dbus-tube.py", line 356, in <lambda>
    test(q, bus, conn, stream, cs.SOCKET_ACCESS_CONTROL_LOCALHOST))
  File "./tubes/offer-muc-dbus-tube.py", line 341, in test
    chan_iface.Close()
  File "/usr/lib64/python2.6/site-packages/dbus/proxies.py", line 140, in __call__
    **keywords)
  File "/usr/lib64/python2.6/site-packages/dbus/connection.py", line 622, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Error.NoReply: Message did not receive a reply (timeout by message bus)
FAIL: tubes/offer-muc-dbus-tube.py

Hmm, that looks kind of scary.

Traceback (most recent call last):
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/gabbletest.py", line 396, in exec_test_deferred
    f(queue, bus, conn, stream)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/file-transfer/file_transfer_helper.py", line 129, in test
    if fct():
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/file-transfer/file_transfer_helper.py", line 195, in check_new_channel
    assert props[cs.FT_DATE] == self.file.date
AssertionError
FAIL: file-transfer/test-receive-file-and-close-socket-while-receiving.py

We've had timezone-related trouble with the date-parsing code before, but I thought it was fixed...

Traceback (most recent call last):
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/gabbletest.py", line 396, in exec_test_deferred
    f(queue, bus, conn, stream)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/tubes/tubetestutil.py", line 358, in <lambda>
    test(q, bus, conn, stream, bytestream_cls, *args))
  File "./tubes/accept-private-dbus-tube.py", line 127, in test
    [EventPattern('dbus-signal', signal='TubeStateChanged', args=[69, 2])])
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/bytestream.py", line 268, in open_bytestream
    return self._socks5_expect_connection(expected_before, expected_after)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/bytestream.py", line 249, in _socks5_expect_connection
    EventPattern('s5b-connected'))
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/bytestream.py", line 19, in wait_events
    events = q.expect_many(*tmp)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/servicetest.py", line 134, in expect_many
    event = self.wait()
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.7.31/work/telepathy-gabble-0.7.31/tests/twisted/servicetest.py", line 189, in wait
    raise TimeoutError
TimeoutError

This is the same issue mentioned in #20635.

(In reply to comment #3)
>     assert props[cs.FT_DATE] == self.file.date
> AssertionError
> FAIL: file-transfer/test-receive-file-and-close-socket-while-receiving.py
> 
> We've had timezone-related trouble with the date-parsing code before, but I
> thought it was fixed...

This is fixed in master, and will be fixed in 0.7.32.

From the original report, it looks like some of the tests are crashing. Can you still reproduce this problem? If so, can you check if tests/twisted/tools/gabble-testing.log has any error messages at the end? Also, you could check whether Gabble generated a core file in tests/twisted/tools/core. If so, you can get a backtrace by running:

libtool --mode=execute gdb tests/twisted/telepathy-gabble-debug tests/twisted/tools/core

Then you run "bt full" at the gdb prompt.

Created attachment 31142 [details]
build-0.8.8.log

With 0.8.8 I only get two test failures now, and they don't look a crash anymore.

Comment on attachment 31142 [details]
build-0.8.8.log

> Traceback (most recent call last):
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/gabbletest.py", line 371, in exec_test_deferred
>     fun(queue, bus, conn, stream)
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/tubes/tubetestutil.py", line 358, in <lambda>
>     test(q, bus, conn, stream, bytestream_cls, *args))
>   File "./tubes/accept-private-dbus-tube.py", line 128, in test
>     [EventPattern('dbus-signal', signal='TubeStateChanged', args=[69, 2])])
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/bytestream.py", line 268, in open_bytestream
>     return self._socks5_expect_connection(expected_before, expected_after)
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/bytestream.py", line 249, in _socks5_expect_connection
>     EventPattern('s5b-connected'))
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/bytestream.py", line 19, in wait_events
>     events = q.expect_many(*tmp)
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 150, in expect_many
>     event = self.wait()
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 209, in wait
>     raise TimeoutError
> TimeoutError
> FAIL: tubes/accept-private-dbus-tube.py

This one is bug #20635.

> Traceback (most recent call last):
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/gabbletest.py", line 371, in exec_test_deferred
>     fun(queue, bus, conn, stream)
>   File "./vcard/set-set-disconnect.py", line 23, in test
>     'stream-iq', iq_type='set', query_ns='vcard-temp', query_name='vCard')
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 133, in expect
>     event = self.wait()
>   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 209, in wait
>     raise TimeoutError
> TimeoutError
> FAIL: vcard/set-set-disconnect.py

This one could be bad. Can you reproduce it reliably? You can pass TWISTED_TESTS=vcard/set-set-disconnect.py to `make check` to just run that test. If so, could you attach the output of `make check TWISTED_TESTS=vcard/set-set-disconnect.py CHECK_TWISTED_VERBOSE=1` and the tests/twisted/tools/gabble-testing.log file from a failing run?

(In reply to comment #7)
> > Traceback (most recent call last):
> >   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/gabbletest.py", line 371, in exec_test_deferred
> >     fun(queue, bus, conn, stream)
> >   File "./vcard/set-set-disconnect.py", line 23, in test
> >     'stream-iq', iq_type='set', query_ns='vcard-temp', query_name='vCard')
> >   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 133, in expect
> >     event = self.wait()
> >   File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.8/work/telepathy-gabble-0.8.8/tests/twisted/servicetest.py", line 209, in wait
> >     raise TimeoutError
> > TimeoutError
> > FAIL: vcard/set-set-disconnect.py
> 
> This one could be bad. Can you reproduce it reliably? You can pass
> TWISTED_TESTS=vcard/set-set-disconnect.py to `make check` to just run that
> test. If so, could you attach the output of `make check
> TWISTED_TESTS=vcard/set-set-disconnect.py CHECK_TWISTED_VERBOSE=1` and the
> tests/twisted/tools/gabble-testing.log file from a failing run?
> 

I can reproduce it 100% of the time, passing these variables makes it not fail. I'll attach the logs anyway, maybe you'll have something interesting in there.

Created attachment 31151 [details]
gabble-testing-0.8.8-debug.log.gz

tests ran with lib built with --enable-debug

Okay, the vCard issue was resolved a while back in the 0.9 branch: <http://git.collabora.co.uk/?p=telepathy-gabble.git;a=commit;h=d22fef51>.

I've cherry-picked it back to 0.8.x <http://git.collabora.co.uk/?p=telepathy-gabble.git;a=commit;h=9a9a24b>; it'll be fixed in 0.8.10 (which will probably happen in the next day or so).

Marking this as fixed, since the remaining issue is tracked by bug #20635. Thanks!

This is still failing:

PASS: file-transfer/test-caps-file-transfer.py
/usr/lib64/python2.6/site-packages/twisted/internet/_sslverify.py:5: DeprecationWarning: the md5 module is deprecated; use hashlib instead
  import itertools, md5
Traceback (most recent call last):
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.14/work/telepathy-gabble-0.8.14/tests/twisted/gabbletest.py", line 369, in exec_test_deferred
    fun(queue, bus, conn, stream)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.14/work/telepathy-gabble-0.8.14/tests/twisted/file-transfer/file_transfer_helper.py", line 129, in test
    if fct():
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.14/work/telepathy-gabble-0.8.14/tests/twisted/file-transfer/file_transfer_helper.py", line 209, in accept_file
    byte_arrays=True)
  File "/usr/lib64/python2.6/site-packages/dbus/proxies.py", line 68, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib64/python2.6/site-packages/dbus/proxies.py", line 140, in __call__
    **keywords)
  File "/usr/lib64/python2.6/site-packages/dbus/connection.py", line 622, in call_blocking
    message, timeout)
DBusException: org.freedesktop.Telepathy.Error.NotAvailable: Could not set up local socket
FAIL: file-transfer/test-receive-file-and-close-socket-while-receiving.py
/usr/lib64/python2.6/site-packages/twisted/internet/_sslverify.py:5: DeprecationWarning: the md5 module is deprecated; use hashlib instead
  import itertools, md5
Traceback (most recent call last):
  File "/usr/lib64/python2.6/site-packages/twisted/internet/base.py", line 374, in fireEvent
    DeferredList(beforeResults).addCallback(self._continueFiring)
  File "/usr/lib64/python2.6/site-packages/twisted/internet/defer.py", line 195, in addCallback
    callbackKeywords=kw)
  File "/usr/lib64/python2.6/site-packages/twisted/internet/defer.py", line 186, in addCallbacks
    self._runCallbacks()
  File "/usr/lib64/python2.6/site-packages/twisted/internet/defer.py", line 328, in _runCallbacks
    self.result = callback(self.result, *args, **kw)
--- <exception caught here> ---
  File "/usr/lib64/python2.6/site-packages/twisted/internet/base.py", line 387, in _continueFiring
    callable(*args, **kwargs)
  File "/var/tmp/portage/net-voip/telepathy-gabble-0.8.14/work/telepathy-gabble-0.8.14/tests/twisted/gabbletest.py", line 360, in exec_test_deferred
    bus = dbus.SessionBus()
  File "/usr/lib64/python2.6/site-packages/dbus/_dbus.py", line 219, in __new__
    mainloop=mainloop)
  File "/usr/lib64/python2.6/site-packages/dbus/_dbus.py", line 108, in __new__
    bus = BusConnection.__new__(subclass, bus_type, mainloop=mainloop)
  File "/usr/lib64/python2.6/site-packages/dbus/bus.py", line 125, in __new__
    bus = cls._new_for_bus(address_or_type, mainloop=mainloop)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoServer: Failed to connect to socket /tmp/dbus-TxXI6iJnx4: Connection refused

with 0.8.14, please reopen. Thanks

Created attachment 37482 [details]
Failing tests

Tons of tests are still failing even after skipping the following due more failures:

        sed     -e '/tubes/d' \
                -e 's:file-transfer/test-receive-file-and-close-socket-while-receiving.py::' \
                -e 's:file-transfer/test-receive-file-and-disconnect.py::' \
                -e 's:file-transfer/test-receive-file-and-sender-disconnect-while-transfering.py::' \
                -e 's:file-transfer/test-receive-file-decline.py::' \
                -e 's:file-transfer/test-receive-file.py::' \
                -e 's:file-transfer/test-send-file-declined.py::' \
                -e 's:file-transfer/test-send-file-wait-to-provide.py::' \
                -e 's:file-transfer/test-send-file-and-cancel-immediately.py::' \
                -e 's:file-transfer/test-receive-file-and-sender-disconnect-while-pending.py::' \
                -e 's:file-transfer/test-send-file-provide-immediately.py::' \
                -e 's:vcard/test-vcard-race.py::' \
                -e 's:vcard/update-rejected.py::' \
                -e 's:jingle/incoming-basics.py::' \
                -i tests/twisted/Makefile.am || die 'sed failed'

With 0.10.2 I am only suffering problems reported in bug 30565

(In reply to comment #13)
> With 0.10.2 I am only suffering problems reported in bug 30565

Let's close this bug in favour of bug #30565 then.