blueman-assistant crashed with blueman.bluez.errors.DBusInProgressError in warp(): Operation already in progress

This happens every time I search for Bluetooth devices.

Status changed to 'Confirmed' because the bug affects multiple users.

Hello,

in source code I found :

/usr/lib/python3/dist-packages/blueman/gui

    def update_progress(self, time, totaltime):
        if not self.discovering:
            return False

        self.__discovery_time += time

        progress = self.__discovery_time / totaltime
        if progress >= 1.0:
            progress = 1.0
        if self.__discovery_time >= totaltime:
            self.StopDiscovery()
            return False

what is distroy_time :

why distroy

can I change the distroy time ?

Could you help me plese to fix this bug ?

My configuration

lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu Disco Dingo (development branch)
Release: 19.04
Codename: disco

Best regards

Battant

Hello,

it semm's a timout dbus problem in connection.py

640 try:
641 message.append(signature=signature, *args)
642 except Exception as e:
643 logging.basicConfig()
644 _logger.error('Unable to set arguments %r according to '
645 'signature %r: %s: %s',
646 args, signature, e.__class__, e)
647 raise
648
649 # make a blocking call
650 reply_message = self.send_message_with_reply_and_block(
651 message, timeout)
652 args_list = reply_message.get_args_list(**get_args_opts)
653 if len(args_list) == 0:
654 return None
655 elif len(args_list) == 1:
656 return args_list[0]
657 else:
658 return tuple(args_list)

change the time. good idea ?

Best regards

Battant

/usr/lib/python3/dist-packages/dbus$ connection.py

551 def call_async(self, bus_name, object_path, dbus_interface, method,
552 signature, args, reply_handler, error_handler,
553 timeout=-1.0, byte_arrays=False,
554 require_main_loop=True, **kwargs):

Best regards

Battant

a complete trace

blueman-manager
_________
Load (/usr/lib/python3/dist-packages/blueman/main/PluginManager.py:60)
['Services', 'PulseAudioProfile']
_________
__load_plugin (/usr/lib/python3/dist-packages/blueman/main/PluginManager.py:133)
loading <class 'blueman.plugins.manager.Services.Services'>
_________
__load_plugin (/usr/lib/python3/dist-packages/blueman/main/PluginManager.py:133)
loading <class 'blueman.plugins.manager.PulseAudioProfile.PulseAudioProfile'>
_________
pa_context_event (/usr/lib/python3/dist-packages/blueman/main/PulseAudioUtils.py:341)
1
/usr/bin/blueman-manager:67: DeprecationWarning: Gtk.Window.get_has_resize_grip is deprecated
  if self.window.get_has_resize_grip():
blueman-manager version 2.0.5 starting
_________
pa_context_event (/usr/lib/python3/dist-packages/blueman/main/PulseAudioUtils.py:341)
2
_________
on_bluez_name_owner_changed (/usr/bin/blueman-manager:96)
org.bluez owner changed to :1.50
_________
get_interface_version (/usr/lib/python3/dist-packages/blueman/bluez/BlueZInterface.py:13)
Detected BlueZ 5
_________
SetAdapter (/usr/lib/python3/dist-packages/blueman/gui/DeviceList.py:271)

_________
on_adapter_changed (/usr/lib/python3/dist-packages/blueman/gui/manager/ManagerToolbar.py:83)
toolbar adapter /org/bluez/hci0
_________
pa_context_event (/usr/lib/python3/dist-packages/blueman/main/PulseAudioUtils.py:341)
3
_________
pa_context_event (/usr/lib/python3/dist-packages/blueman/main/PulseAudioUtils.py:341)
4
_________
on_pa_ready (/usr/lib/python3/dist-packages/blueman/plugins/manager/PulseAudioProfile.py:29)
connected
_________
<lambda> (/usr/lib/python3/dist-packages/blueman/main/PulseAudioUtils.py:353)
1
_________
__init__ (/usr/lib/python3/dist-packages/blueman/gui/manager/ManagerProgressbar.py:23)
hiding <ManagerProgressbar.ManagerProgressbar object at 0x7f94e8218048 (blueman+gui+manager+ManagerProgressbar+ManagerProgressbar at 0x1feac00)>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/blueman/bluez/errors.py", line 146, in warp
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/blueman/bluez/Adapter.py", line 139, in stop_discovery
    self.get_interface().StopDiscovery()
  File "/usr/lib/python3/dist-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib/python3/dist-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
dbus.exceptions.DBusException: org.bluez.Error.InProgress: Operation already in progress

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/blueman/gui/DeviceList.py", line 311, in update_progress
    self.StopDiscovery()
  File "/usr/lib/python3/dist-packages/blueman/gui/DeviceList.py", line 419, in StopDiscovery
    self.Adapter.stop_discovery()
  File "/usr/lib/python3/dist-packages/blueman/bluez/errors.py", line 148, in warp
    raise parse_dbus_error(exception)
blueman.bluez.errors.DBusInProgressError: Operation already in progress

Best regards

Battant

Hello,

I tried to locking for the bug :

Here is my result :

In /usr/lib/python3/dist-packages/dbus/proxies.py

615 def call_blocking(self, bus_name, object_path, dbus_interface, method,
616 signature, args, timeout=2.0,
617 byte_arrays=False, **kwargs):
618 """Call the given method, synchronously.
619 :Since: 0.81.0
620 """
621 if object_path == LOCAL_PATH:
622 raise DBusException('Methods may not be called on the reserved '
623 'path %s' % LOCAL_PATH)
624 if dbus_interface == LOCAL_IFACE:
625 raise DBusException('Methods may not be called on the reserved '
626 'interface %s' % LOCAL_IFACE)
627 # no need to validate other args - MethodCallMessage ctor will do
628
629 get_args_opts = dict(byte_arrays=byte_arrays)
630 if is_py2:
631 get_args_opts['utf8_strings'] = kwargs.get('utf8_strings', False )
632 elif 'utf8_strings' in kwargs:
633 raise TypeError("unexpected keyword argument 'utf8_strings'")

634
635 message = MethodCallMessage(destination=bus_name,
636 path=object_path,
637 interface=dbus_interface,
638 method=method)
639 # Add the arguments to the function
640 try:
641 message.append(signature=signature, *args)
642 except Exception as e:
643 logging.basicConfig()
644 _logger.error('Unable to set arguments %r according to '
645 'signature %r: %s: %s',
646 args, signature, e.__class__, e)
647 raise
648 # make a blocking call
649
650
651 print ("message : ",message)
652 print("timeout",timeout)
653
654 _logger.info ("message : ",message)
655 _logger.info("timeout",timeout)

657 print ("reply meaage : ",self.send_message_with_reply_and_block(
658 message, timeout))
659 _logger.info ("reply meaage : ",self.send_message_with_reply_and_blo ck(
660 message, timeout))
the program crash at this line.

661 reply_message = self.send_message_with_reply_and_block(
662 message, timeout)
663 # reply_message = self.send_message_with_reply_and_block(message,time out)
664 args_list = reply_message.get_args_list(**get_args_opts)
665 if len(args_list) == 0:
666 return None
667 elif len(args_list) == 1:
668 return args_list[0]
669 else:
670 return tuple(args_list)
this lines is never execute :

128 print ("poxis ignore_reply : ",ignore_reply )
129 print ("proxis reply_handler : ",reply_handler)
130 if ignore_reply or reply_handler is not None:
131 self._connection.call_async(self._named_service,
132 self._object_path,
133 dbus_interface,
134 self._m...

Got this after pairing of my Logitech M555b mouse on Ubuntu MATE 19.10 beta.