Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

D-bus error #17

Open
najaB76 opened this issue Jun 5, 2022 · 4 comments
Open

D-bus error #17

najaB76 opened this issue Jun 5, 2022 · 4 comments

Comments

@najaB76
Copy link

najaB76 commented Jun 5, 2022 •
edited

Looking for some advice. I managed to set up the connection to a SmartSolar 250/70. It was working fine for a week or two, sending data to a MQTT logger. A couple of days ago it stopped working, and is throwing two different errors in the log:

It either fails to connect with this error:

[ERROR  ] (2022-06-05 10:36:46,588) victron_gatt.py::56 smartsolar1: Connection failed: 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.!

Or it connects and then throws this one:

[ERROR  ] (2022-06-05 10:01:24,054) connection.py::236 Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/dbus/connection.py", line 232, in maybe_handle_message
    self._handler(*args, **kwargs)
  File "/usr/lib/python3.8/site-packages/gatt/gatt_linux.py", line 398, in properties_changed
    self.services_resolved()
  File "/data/home/root/victron-master/lib/victron_bluetooth/victron_gatt.py", line 85, in services_resolved
    self.start_send_init_squence()
  File "/data/home/root/victron-master/lib/victron_bluetooth/victron_gatt.py", line 153, in start_send_init_squence
    self.send_init_sequence()
  File "/data/home/root/victron-master/lib/victron_bluetooth/victron_gatt.py", line 159, in send_init_sequence
    c = self.characteristics[uuid]
KeyError: '306b0002-b081-4037-83dc-e59fcc3cdfd0'

I'm using the built-in Bluetooth connection in a Raspberry Pi 3B+. The SmartSolar is connected as shown in bluetoothctl:

Device C7:FB:23:EF:97:A3 (random)
        Name: SmartSolar HQ1950WPKXP
        Alias: SmartSolar HQ1950WPKXP
        Paired: yes
        Trusted: yes
        Blocked: no
        Connected: yes
        LegacyPairing: no
        UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
        UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
        UUID: Vendor specific           (306b0001-b081-4037-83dc-e59fcc3cdfd0)
        UUID: Vendor specific           (68c10001-b17f-4d3a-a290-34ad6499937c)
        UUID: Vendor specific           (97580001-ddf1-48be-b73e-182664615d8e)
        ManufacturerData Key: 0x02e1
        ManufacturerData Value:
  01 aa 3d 3e a5 9a a4 26 82 0b 00 00 6d 84 ed 5b  ..=>...&....m..[
        AdvertisingFlags:
  00                                               .
        AdvertisingData Key: 0x00 (0)
        AdvertisingData Value:
  ff e1 02 02 aa 3d 3e 9a 7f 0d 82 0b 54 87 54 db  .....=>.....T.T.
  3e 77 67 03 d8 35 f0 6a 4f f6 c2 d9 e7           >wg..5.jO....

I've removed and rediscovered the SmartSolar and can't see anything wrong there:

[bluetooth]# remove C7:FB:23:EF:97:A3
[DEL] Descriptor (Handle 0xec70)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a/char000b/desc000d
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0xb288)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a/char000b
        00002a05-0000-1000-8000-00805f9b34fb
        Service Changed
[DEL] Primary Service (Handle 0x0020)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a
        00001801-0000-1000-8000-00805f9b34fb
        Generic Attribute Profile
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char000f/desc0011
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0xa098)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char000f
        68c10002-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[DEL] Characteristic (Handle 0x50a0)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char0012
        68c10003-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[DEL] Primary Service (Handle 0x0020)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e
        68c10001-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[DEL] Characteristic (Handle 0x7b98)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0015
        97580002-ddf1-48be-b73e-182664615d8e
        Vendor specific
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0017/desc0019
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0x7040)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0017
        97580003-ddf1-48be-b73e-182664615d8e
        Vendor specific
[DEL] Characteristic (Handle 0x6878)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001a
        97580004-ddf1-48be-b73e-182664615d8e
        Vendor specific
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001c/desc001e
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0x5d38)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001c
        97580006-ddf1-48be-b73e-182664615d8e
        Vendor specific
[DEL] Primary Service (Handle 0x0020)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014
        97580001-ddf1-48be-b73e-182664615d8e
        Vendor specific
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0020/desc0022
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0x49c0)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0020
        6b0002b0-8140-3700-83dc-e59fcc3cdfd0
        Vendor specific
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0023/desc0025
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0x3588)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0023
        306b0003-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[DEL] Descriptor (Handle 0xf2bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0026/desc0028
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[DEL] Characteristic (Handle 0x2588)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0026
        306b0004-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[DEL] Primary Service (Handle 0x0020)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f
        306b0001-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[DEL] Device C7:FB:23:EF:97:A3 SmartSolar HQ1950WPKXP
Device has been removed

And then re-added:

[CHG] Device C7:FB:23:EF:97:A3 Connected: yes
Connection successful
[NEW] Primary Service (Handle 0x88bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a
        00001801-0000-1000-8000-00805f9b34fb
        Generic Attribute Profile
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a/char000b
        00002a05-0000-1000-8000-00805f9b34fb
        Service Changed
[NEW] Descriptor (Handle 0x6e54)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000a/char000b/desc000d
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Primary Service (Handle 0x88bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e
        68c10001-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char000f
        68c10002-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[NEW] Descriptor (Handle 0x8474)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char000f/desc0011
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service000e/char0012
        68c10003-b17f-4d3a-a290-34ad6499937c
        Vendor specific
[NEW] Primary Service (Handle 0x88bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014
        97580001-ddf1-48be-b73e-182664615d8e
        Vendor specific
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0015
        97580002-ddf1-48be-b73e-182664615d8e
        Vendor specific
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0017
        97580003-ddf1-48be-b73e-182664615d8e
        Vendor specific
[NEW] Descriptor (Handle 0xa18c)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char0017/desc0019
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001a
        97580004-ddf1-48be-b73e-182664615d8e
        Vendor specific
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001c
        97580006-ddf1-48be-b73e-182664615d8e
        Vendor specific
[NEW] Descriptor (Handle 0xaf84)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service0014/char001c/desc001e
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Primary Service (Handle 0x88bc)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f
        306b0001-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[NEW] Characteristic (Handle 0x77a0)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0020
        6b0002b0-8140-3700-83dc-e59fcc3cdfd0
        Vendor specific
[NEW] Descriptor (Handle 0xcf4c)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0020/desc0022
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0023
        306b0003-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[NEW] Descriptor (Handle 0xdd04)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0023/desc0025
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Characteristic (Handle 0x8894)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0026
        306b0004-b081-4037-83dc-e59fcc3cdfd0
        Vendor specific
[NEW] Descriptor (Handle 0xece4)
        /org/bluez/hci0/dev_C7_FB_23_EF_97_A3/service001f/char0026/desc0028
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[CHG] Device C7:FB:23:EF:97:A3 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Device C7:FB:23:EF:97:A3 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Device C7:FB:23:EF:97:A3 UUIDs: 306b0001-b081-4037-83dc-e59fcc3cdfd0
[CHG] Device C7:FB:23:EF:97:A3 UUIDs: 68c10001-b17f-4d3a-a290-34ad6499937c
[CHG] Device C7:FB:23:EF:97:A3 UUIDs: 97580001-ddf1-48be-b73e-182664615d8e
[CHG] Device C7:FB:23:EF:97:A3 ServicesResolved: yes

And pairing:

[bluetooth]# scan on
[NEW] Device C7:FB:23:EF:97:A3 SmartSolar HQ1950WPKXP
[bluetooth]# pair  C7:FB:23:EF:97:A3
Attempting to pair with C7:FB:23:EF:97:A3
[CHG] Device C7:FB:23:EF:97:A3 Connected: yes
Request passkey
[agent] Enter passkey (number in 0-999999): xxxxxx
Pairing successful
[SmartSolar HQ1950WPKXP]#

Any thoughts or suggestions?

Edit: Forgot to mention, system has been rebooted several times.
@birdie1
Copy link
Owner

birdie1 commented Jun 7, 2022

Sounds like the characteristics of the SmartSolar changed or it didn't pair successful (What I do not believe from your bluetoothctl log).
Was there an update of the SmartSolar recently?
Which Version is it?
On which commit you are using this repository?

@najaB76
Copy link
Author

najaB76 commented Jun 8, 2022 •
edited

Hello.

  • No, there was no update to the SmartSolar.
  • I'll need to double-check the version (it isn't local to me so I need someone to log on to Victron Connect) but it was updated to the firmware version that was current back in March.
  • I first installed a couple of weeks ago.

Rather annoyingly, I have now locked myself out of the Raspberry Pi temporarily.

@najaB76
Copy link
Author

najaB76 commented Jul 28, 2022

Circling back around to this. The version is 1.59.

It has started connecting again, but when I run victron.py in debug mode there are unrecognised values all over:

[DEBUG  ] (2022-07-28 14:17:56,854) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b'\x08\x03\x19\xec X \x8d\xed\xff\xff\xff\xff\xff\xff\xec\xed\xff\xff\xff': 'unknown command (in var len) 0x8a in dict_keys([140, 141, 142, 125, 143, 188, 189, 187, 239, 240, 246])'
[DEBUG  ] (2022-07-28 14:17:56,856) victron_bluetooth.py::279 UNRECOGNIZED DATA: smartsolar1: unknown single packet: value:b'\xff\xff\xff>\xec\xff\xff\xff\xff\xff\xff\x8c\xed\xff\xff\xff\xff\xff\xff' - value_origin:b'\xff\xff\xff>\xec\xff\xff\xff\xff\xff\xff\x8c\xed\xff\xff\xff\xff\xff\xff'
[DEBUG  ] (2022-07-28 14:17:56,899) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b'\x08\x03\x19\xed\x8fB\xdb\x01\x08\x03\x19\xed\x8cD\x8c\xb9\x00\x00\x08\x03': 'unknown command (in var len) 0x8a in dict_keys([140, 141, 142, 125, 143, 188, 189, 187, 239, 240, 246])'
[DEBUG  ] (2022-07-28 14:17:56,903) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b'\x19\xec\x8aB<\x05\x08\x03\x19\xed\xbcDp\x0b\x02\x00\x08\x03\x19\xed': 'unknown command (in var len) 0x8a in dict_keys([140, 141, 142, 125, 143, 188, 189, 187, 239, 240, 246])'
[DEBUG  ] (2022-07-28 14:17:56,905) victron_bluetooth.py::279 UNRECOGNIZED DATA: smartsolar1: unknown single packet: value:b'\xbbB\xc8J' - value_origin:b'\xbbB\xc8J'
[DEBUG  ] (2022-07-28 14:17:56,908) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b"\x08\x03\x19 'Dp\x0b\x02\x00": 538510088
[DEBUG  ] (2022-07-28 14:17:56,912) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b'\x08\x03\x19 \x13D\x8c\xb9\xff\xff': 538510088
[DEBUG  ] (2022-07-28 14:17:57,407) victron_bluetooth.py::279 UNRECOGNIZED DATA: smartsolar1: unknown single packet: value:b'\xecZD\xad\xc3\xb8\x00' - value_origin:b'\x08\x03\x19\xecZD\xad\xc3\xb8\x00'
[DEBUG  ] (2022-07-28 14:17:57,617) victron_gatt.py::117 UNRECOGNIZED DATA: smartsolar1: error handling: b'\x08\x03\x19\x02\x07D\x00\x00\x00\x00': 35193608

Could this be related to the connection issues that I'm seeing?

@birdie1
Copy link
Owner

birdie1 commented Jul 30, 2022

We still have not decoded many of the values which are returned by the device and print these out in debug mode.
Do you get any output, or just the debug data?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@birdie1 @najaB76