kolinger / rd-usb

Web GUI for RuiDeng/Riden USB testers (UM34C, UM24C, UM25C, TC66C)
GNU General Public License v3.0
223 stars 29 forks source link

How to properly reconnect to device #28

Closed Bluscream closed 2 years ago

Bluscream commented 2 years ago

After the device loses power i can't seem to get it working again without a reboot

I tried executing all this:

sudo rfkill # Check if Bluetooth is blocked
# hcitool scan
# sudo systemctl stop serial-getty@USB0.service
sudo rfcomm release 0 # Unbind serial port from Bluetooth device
sudo rfkill # Check if Bluetooth is blocked
sudo rfcomm bind 0 00:16:A6:00:1C:E3 # Bind serial port to Bluetooth device
sudo ls -al /dev/rfcomm* # List all serial ports
# sudo usermod -a -G dialout blu
sudo chown blu:blu /dev/rfcomm0 # Own serial port
cd /srv/usbmeter/rd-usb/
python /srv/usbmeter/rd-usb/web.py --daemon --prefix /usb/ # Start daemon

Log looks like this:

2022-03-29 14:53:14 - Disconnected
2022-03-29 15:01:28 - Connecting
2022-03-29 15:01:28 - Connected
2022-03-29 15:01:33 - operation failed, retrying
Traceback (most recent call last):
  File "/srv/usbmeter/rd-usb/webapp/backend.py", line 297, in retry
    return callback()
  File "/srv/usbmeter/rd-usb/interfaces/wrapper.py", line 48, in read
    return self.get_result(60)
  File "/srv/usbmeter/rd-usb/interfaces/wrapper.py", line 64, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/srv/usbmeter/rd-usb/interfaces/wrapper.py", line 101, in call
    result = callback()
  File "/srv/usbmeter/rd-usb/interfaces/um.py", line 40, in read
    data = self.serial.read(130)
  File "/home/blu/.local/lib/python3.9/site-packages/serial/serialposix.py", line 595, in read
    raise SerialException(
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

I also tried some of the stuff in https://gist.github.com/0/c73e2557d875446b9603 without much success;

[bluetooth]# power on
Changing power on succeeded
[bluetooth]# connect 00:16:A6:00:1C:E3
Attempting to connect to 00:16:A6:00:1C:E3
[CHG] Device 00:16:A6:00:1C:E3 Connected: yes
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -94
[CHG] Device 00:16:A6:00:1C:E3 ServicesResolved: yes
Failed to connect: org.bluez.Error.NotAvailable
[CHG] Device 00:16:A6:00:1C:E3 ServicesResolved: no
[CHG] Device 00:16:A6:00:1C:E3 Connected: no
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -75
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -90
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -73
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -83
[bluetooth]# info 00:16:A6:00:1C:E3
Device 00:16:A6:00:1C:E3 (public)
        Name: UM34C
        Alias: UM34C
        Class: 0x00001f00
        Paired: yes
        Trusted: yes
        Blocked: no
        Connected: no
        LegacyPairing: no
        UUID: Serial Port               (00001101-0000-1000-8000-00805f9b34fb)
        UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
        Modalias: usb:v05ACp0239d0644
        ManufacturerData Key: 0x050e
        ManufacturerData Value:
  e3 1c 00 a6 16 00                                ......
        RSSI: -74
[CHG] Device 00:16:A6:00:1C:E3 RSSI: -92
kolinger commented 2 years ago

I get this error too but after while it connects successfully.

If it persists then something may be actually using the serial port? In such case what this command reports: fuser -n file /dev/rfcomm0?

This commands should output what PID is using /dev/rfcomm0 with output like:

fuser -n file /dev/rfcomm0
/dev/rfcomm0:        1507085

And then cat /proc/1507085/cmdline can be used to identify what the process is.

If this returns nothing then Bluetooth may be in some broken state perhaps after non-clean connection exit. I would try to somehow reset Bluetooth but I'm not sure how to do that on your device. Maybe something along these lines - reset bluetooth adapter - could help?

Bluscream commented 2 years ago

If it persists then something may be actually using the serial port? In such case what this command reports: fuser -n file /dev/rfcomm0?

blu@minopia:/srv/usbmeter/rd-usb $ sudo fuser -n file /dev/rfcomm0
blu@minopia:/srv/usbmeter/rd-usb $

sudo hciconfig hci0 reset

resulted in the same "readyness" error, sadly

The "pinging" was unsuccessful aswell

blu@minopia:/srv/usbmeter/rd-usb $ sudo l2ping -c 1 00:16:A6:00:1C:E3
Can't connect: Host is down
kolinger commented 2 years ago

In my case this errors happens only when connection is starting/ending or when Bluetooth signal is bad. It will clear itself after 10 seconds or so. Do you have good signal? Is your USB meter really close to your PI?

Try to connect to your USB meter from another computer to rule issues related to USB meter.

There is know issue with UM34C where construction leads to bad connection between Bluetooth module and main microcontroller see here and here. If you have issues connecting from another device and USB meter is close (signal is good) then this could be your issue.

There are always last resort options like rebooting PI and re-powering USB meter. This should fix the issue but of course it isn't practical and if it doesn't fix the issue then there is likely HW issue like the mentioned above.

Bluscream commented 2 years ago

Maybe it would be good to implement some basic bt functionality into the UI like showing a list of devices in range with their signal strength and potentially buttons to reset/reconnect

kolinger commented 2 years ago

I would be nice but I don't believe the effort is worth it - it's not easy. The problem would be to create something that works on all platforms (linux, windows). Pybluez could help but for example signal strength could be problem to do at all. It is something that I did think about but didn't find enough motivation to do.

kolinger commented 2 years ago

I today tried reconnects on Raspberry PI 4 (2GB, 32-bit) and it worked fine. I tried going out of range and back. I also disconnected power from USB meter and powered it back. In all cases Bluetooth did give me the error (device reports readiness to read but returned no dat) or Timeout error once or twice but then it connected and started transferring data without doing anything. Same behavior was observed on my second Linux/Debian x86 machine.

Like this:

2022-03-31 13:50:05 - Connecting
2022-03-31 13:50:06 - Connected
2022-03-31 13:50:06 - {"timestamp": 1648727406.4939814, "voltage": 5.02, "current": 0.0, "power": 0.0, "temperature": 19, "data_plus": 0.0, "data_minus": 0.0, "mode_id": 7, "mode_name": "DCP1.5A", "accumulated_current": 0, "accumulated_power": 0, "accumulated_time": 0, "resistance": 9999.9}
2022-03-31 13:50:07 - {"timestamp": 1648727407.507421, "voltage": 5.02, "current": 0.0, "power": 0.0, "temperature": 19, "data_plus": 0.0, "data_minus": 0.0, "mode_id": 7, "mode_name": "DCP1.5A", "accumulated_current": 0, "accumulated_power": 0, "accumulated_time": 0, "resistance": 9999.9}
2022-03-31 13:50:29 - operation failed, retrying
Traceback (most recent call last):
  File "/opt/rd-usb/webapp/backend.py", line 297, in retry
    return callback()
  File "/opt/rd-usb/interfaces/wrapper.py", line 48, in read
    return self.get_result(60)
  File "/opt/rd-usb/interfaces/wrapper.py", line 64, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/opt/rd-usb/interfaces/wrapper.py", line 101, in call
    result = callback()
  File "/opt/rd-usb/interfaces/um.py", line 40, in read
    data = self.serial.read(130)
  File "/opt/virtualenvs/rd-usb/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

2022-03-31 13:50:33 - {"timestamp": 1648727433.3100023, "voltage": 5.02, "current": 0.0, "power": 0.0, "temperature": 20, "data_plus": 0.01, "data_minus": 0.0, "mode_id": 7, "mode_name": "DCP1.5A", "accumulated_current": 0, "accumulated_power": 0, "accumulated_time": 0, "resistance": 9999.9}
2022-03-31 13:50:33 - {"timestamp": 1648727433.6512835, "voltage": 5.02, "current": 0.0, "power": 0.0, "temperature": 20, "data_plus": 0.01, "data_minus": 0.0, "mode_id": 7, "mode_name": "DCP1.5A", "accumulated_current": 0, "accumulated_power": 0, "accumulated_time": 0, "resistance": 9999.9}
...

In result I can't reproduce your case where reboot is required and thus I'm unable to debug this issue. In any case this is issue with Bluetooth - rd-usb application can't do anything about this.

I'm afraid I can't help you much with this.

Bluscream commented 2 years ago

Little update:

https://youtu.be/VCU81PfSlcI?t=167

kolinger commented 2 years ago

Hi, did you try it? Does it work for you?

Here is detailed description https://scribles.net/setting-up-bluetooth-serial-port-profile-on-raspberry-pi/ of the fix. It boils down to: The fix should be done by editing /etc/systemd/system/dbus-org.bluez.service and adjusting following line: ExecStart=/usr/lib/bluetooth/bluetoothd by appending -C on the end resulting in: ExecStart=/usr/lib/bluetooth/bluetoothd -C And adding extra line under ExecStart=/usr/lib/bluetooth/bluetoothd -C with following content: ExecStartPost=/usr/bin/sdptool add SP.

First modification enables deprecated CLI (I guess because sdptool is deprecated). Second modification registers bluetooth serial port service on boot.

I'm not sure how this could fix this issue though. I see how does it fix serial port bluetooth functionality for some users, but why would it help if serial port is already working and just stops working after disconnect? I don't have this modification on my raspberry pi and reconnect is working fine. I do get the message but it starts working by itself after few seconds. Maybe it would make more sense to call sdptool add SP when it stops working?