Unresponsiveness/crash when name is queried on a newly found renderer

[anantkamath]

If a client listening to the FoundRenderer signal queries the FriendlyName or any other property of the newly found renderer immediately, the renderer dbus service freezes. This and all subsequent calls then result in errors ["org.freedesktop.DBus.Error.NoReply", "Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken."]

I'm testing with my own C++ QtDBus client on Arch linux with dleyna-renderer-0.5.0. The same behaviour is also observed with https://github.com/linuxdeepin/deepin-movie which uses PyQt.

Steps to reproduce:

1. Start client that listens to the FoundRenderer signal
2. Turn on a DLNA renderer (eg. TV)
3. Try to read the FriendlyName or any other property upon receiving the signal
   This results in a crash/freeze

Adding an usleep(1000*1000); after the signal is received, before trying to read the FriendlyName prevents the crash for some reason.

[anantkamath]

Code to reproduce this issue (using dbus-python and python2):

from dbus.mainloop.glib import DBusGMainLoop
from gi.repository import GObject
import dbus
import time

def handler(arg1=None):
    print "Found renderer %r" % arg1
    r = bus.get_object('com.intel.dleyna-renderer',
                      arg1)
    #time.sleep(1) #Uncommenting this line 'fixes' this bug
    props_iface = dbus.Interface(r, 'org.freedesktop.DBus.Properties')
    properties = props_iface.Get("com.intel.dLeynaRenderer.RendererDevice", "FriendlyName")
    print properties

DBusGMainLoop(set_as_default=True)

bus = dbus.SessionBus()
manager = bus.get_object('com.intel.dleyna-renderer',
                      '/com/intel/dLeynaRenderer')

manager.connect_to_signal("FoundRenderer", handler, "com.intel.dLeynaRenderer.Manager")

loop = GObject.MainLoop()
loop.run()

Steps to reproduce:
Run the script above.

If a DLNA renderer device is already running or started after the script is started results in the
GetAll call blocking and finally returning "org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken."

Output:

Found renderer dbus.ObjectPath('/com/intel/dLeynaRenderer/server/0')
ERROR:dbus.connection:Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 230, in maybe_handle_message
    self._handler(*args, **kwargs)
  File "pyd.py", line 12, in handler
    properties = props_iface.Get("com.intel.dLeynaRenderer.RendererDevice", "FriendlyName")
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.

Killing and restarting the script results in all calls to the dleyna-renderer service resulting in the same error.

Uncommenting the line which adds time.sleep(1) 'fixes' the issue.

[phako]

You can/should delay the signal handler through the mainloop, in Qt you can a use Qt::QueuedConnection for this. otherwise you're deadlocking yourself.

dLeyna sends the signal, waits for it to return while you in the signal handler wait do a DBus call to dLeyna which you wait for returning => deadlock

[phako]

Although this might be related to the use of gupnp_service_info_get_introspection:

#0  0x0000003897ae4cc9 in syscall () from /export/target/bxt/f20/RFS1/lib64/libc.so.6
#1  0x000000389a28c5ff in g_cond_wait (cond=cond@entry=0x14b0358, mutex=mutex@entry=0x14b0350) at /usr/src/debug/glib-2.0/1_2.44.1-r0/glib-2.44.1/glib/gthread-posix.c:1412
#2  0x000000389c873ea4 in get_connection (should_cleanup=<optimized out>, item=0x16aa9a0) at /usr/src/debug/libsoup-2.4/2.50.0-r0/libsoup-2.50.0/libsoup/soup-session.c:1957
#3  soup_session_process_queue_item (session=<optimized out>, item=0x16aa9a0, should_cleanup=<optimized out>, loop=<optimized out>)
    at /usr/src/debug/libsoup-2.4/2.50.0-r0/libsoup-2.50.0/libsoup/soup-session.c:2007
#4  0x000000389c87479e in soup_session_real_send_message (session=0x14b03a0, msg=0x14bcd50) at /usr/src/debug/libsoup-2.4/2.50.0-r0/libsoup-2.50.0/libsoup/soup-session.c:2257
#5  0x0000003899a1ce75 in gupnp_service_info_get_introspection (info=0x16c32d0, error=0x7fffbd93e8c8) at /usr/src/debug/gupnp/0.20.16-r0/gupnp-0.20.16/libgupnp/gupnp-service-info.c:599
#6  0x00007fad781d65f7 in prv_get_av_service_states_values (can_get_byte_pos=0x16af8d8, max_rate=0x16af8d0, min_rate=0x16af8c8, upnp_tp_speeds=0x16af8a8, mpris_tp_speeds=0x16af8b8, 
    av_proxy=0x16c32d0) at /build/tmp/work/corei7-64-mel-linux/dleyna-renderer/0.6.0-r0/git/libdleyna/renderer/device.c:2156
#7  prv_props_update (device=0x16af850, task=0x14dd500)
    at /build/tmp/work/corei7-64-mel-linux/dleyna-renderer/0.6.0-r0/git/libdleyna/renderer/device.c:2391
#8  0x00007fad781d7c51 in dlr_device_get_prop (device=<optimized out>, task=0x14dd500, cb=<optimized out>)
    at /build/tmp/work/corei7-64-mel-linux/dleyna-renderer/0.6.0-r0/git/libdleyna/renderer/device.c:2722
#9  0x00007fad77fbfbcf in prv_process_task (user_data=0x14e8380) at /usr/src/debug/dleyna-core/0.6.0-r0/git/libdleyna/core/task-processor.c:382
#10 0x000000389a24873a in g_main_dispatch (context=0x145f130) at /usr/src/debug/glib-2.0/1_2.44.1-r0/glib-2.44.1/glib/gmain.c:3122
#11 g_main_context_dispatch (context=context@entry=0x145f130) at /usr/src/debug/glib-2.0/1_2.44.1-r0/glib-2.44.1/glib/gmain.c:3737
#12 0x000000389a248ab8 in g_main_context_iterate (context=0x145f130, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>)
    at /usr/src/debug/glib-2.0/1_2.44.1-r0/glib-2.44.1/glib/gmain.c:3808
#13 0x000000389a248dd2 in g_main_loop_run (loop=0x1478140) at /usr/src/debug/glib-2.0/1_2.44.1-r0/glib-2.44.1/glib/gmain.c:4002
#14 0x00007fad77fbedbc in dleyna_main_loop_start (server=<optimized out>, control_point=<optimized out>, user_data=0x0) at /usr/src/debug/dleyna-core/0.6.0-r0/git/libdleyna/core/main-loop.c:158
#15 0x0000003897a205e0 in __libc_start_main () from /export/target/bxt/f20/RFS1/lib64/libc.so.6
#16 0x0000000000400979 in _start ()