m-pavel / go-tion

Tion Breazer golang API
Apache License 2.0
22 stars 4 forks source link

Expecting 20 bytes array. Got 1 #2

Open kdeyko opened 3 years ago

kdeyko commented 3 years ago

Hi there! First of all, thanks for your project, it's been working perfectly stable!.. until today, when the short circuit happened in my flat and the entire electrical system was down. After restoring it, I notices that the go-tion (running via MQTT on a separate machine inside a docker container) seemed broken: container works, the app is running, but no updates in MQTT broker. Well, actually there ARE updates, but only about "offline" status in "nn/tion-aval" topic. I've rebooted everything but still getting these errors in logs:

MQTT WARNING  22:31:50 memstore.go:137: [store]    memorystore wiped
2020/12/19 22:31:50 hassio.go:260: MQTT Connected to cube:1883. Topic is 'nn/tion'. Control topic is 'nn/tion-control'. Availability topic is 'nn/tion-aval'
2020/12/19 22:31:51 hassio.go:187: Starting main loop with 30 s. interval.
2020/12/19 22:32:21 hassio.go:202: [0] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:32:52 hassio.go:202: [1] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:33:22 hassio.go:202: [2] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:33:53 hassio.go:202: [3] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:34:23 hassio.go:202: [4] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:34:54 hassio.go:202: [5] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:35:24 hassio.go:202: [6] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:35:54 hassio.go:202: [7] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:36:25 hassio.go:202: [8] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:36:55 hassio.go:202: [9] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:37:26 hassio.go:202: [10] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:37:56 hassio.go:202: [11] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:38:26 hassio.go:202: [12] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:38:57 hassio.go:202: [13] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:39:27 hassio.go:202: [14] R6: Expecting 20 bytes array. Got 1
2020/12/19 22:39:57 hassio.go:195: Fail limit reached (15). Exiting.

Could you please help me to solve this issue?

kdeyko commented 3 years ago

Just checked: the control still works via official mobile app, so it seems that Tion itself is functional.

kdeyko commented 3 years ago

That's weird, but I think I've solved the issue, though I don't quite understand what of my actions helped exactly. What I did (besides rebooting everything) :

  1. Unplugged and plugged back in the Bluetooth USB-stick.
  2. Restarted the BT service: sudo systemctl restart bluetooth
  3. Restarted the go-tion app (docker container in my case): docker stop go-tion && docker start go-tion
  4. Started the bluetoothctl utility and ran info while being already connected to Tion breezer:
    
    kdeyko@netbook:~/home/go-tion$ bluetoothctl
    [NEW] Controller 00:1A:7D:DA:71:13 netbook [default]
    [NEW] Device E4:93:6E:ED:9B:94 Tion Breezer 3S
    [NEW] Primary Service
    /org/bluez/hci0/dev_E4_93_6E_ED_9B_94/service0009
    6e400001-b5a3-f393-e0a9-e50e24dcca9e
    Nordic UART Service
    [NEW] Characteristic
    /org/bluez/hci0/dev_E4_93_6E_ED_9B_94/service0009/char000d
    6e400002-b5a3-f393-e0a9-e50e24dcca9e
    Nordic UART TX
    [NEW] Characteristic
    /org/bluez/hci0/dev_E4_93_6E_ED_9B_94/service0009/char000a
    6e400003-b5a3-f393-e0a9-e50e24dcca9e
    Nordic UART RX
    [NEW] Descriptor
    /org/bluez/hci0/dev_E4_93_6E_ED_9B_94/service0009/char000a/desc000c
    00002902-0000-1000-8000-00805f9b34fb
    Client Characteristic Configuration
    [NEW] Primary Service
    /org/bluez/hci0/dev_E4_93_6E_ED_9B_94/service0008
    00001801-0000-1000-8000-00805f9b34fb
    Generic Attribute Profile
    Agent registered

[Tion Breezer 3S]# info Device E4:93:6E:ED:9B:94 (random) Name: Tion Breezer 3S Alias: Tion Breezer 3S Paired: yes Trusted: no 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: Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e) [Tion Breezer 3S]# quit



Right after that, I've noticed that nn/tion-aval now shows "online" in MQTT Explorer. And everything works fine now.

Hope this helps someone as unlucky as me.
m-pavel commented 3 years ago

Thanks for the feedback. This is kind of issue I'm facing every 2-3 month on my Raspberry PI installation. Usually helps adaptor reset like described here. I'm trying to find out the reason of it but it's quite complicated to have debug sessions once every 2 month.

kdeyko commented 3 years ago

Yep, I also tried that “adapter reset”, but it didn’t help, at least immediately. Anyway, thank you for the project, it’s more stable than the one I used previously. Also, I think I can help debugging the issue once I face it again, if you wish. I could send more logs, experiment with the settings, etc. Just ping me in telegram @kdeyko.

kdeyko commented 3 years ago

JFYI, I just got the same issue and I think I know how to reproduce it: just turn off the power of Tion completely. In my case I opened a lid to check the filters - this cuts the power off too. This time only complete reboot of hosting machine helped me to get rid of that "Expecting 20 bytes array. Got 1" stuff.

kdeyko commented 3 years ago

I'm reopening this since the issue still occurs from time to time and there is no good enough workaround to mitigate it. It turned out that my previously mentioned actually didn't solve the issue, it was just a coincidence that the system started to work. As I said in the last comment, there is a way to reproduce the issue: you just need to turn off the power of Tion completely. So the debugging is now possible. Please let me know if I can help with this somehow. Thanks!

kdeyko commented 3 years ago

I think I've found a workaround:

  1. Stop the BT service: sudo systemctl stop bluetooth
  2. Connect to your Tion via smartphone app "Tion Remote"
  3. Start the BT service: sudo systemctl start bluetooth
  4. Wait for a minute...
  5. Profit! You are awesome!

At least it worked for me.