Emonhub: Bluetooth not available

Hi guys,
I’ve been updating with Bluetooth and an SMA inverter. The emonhub.log says “2020-07-28 08:01:52,836 WARNING SMASolar Bluetooth not available…” but “sudo service bluetooth status” say:

● bluetooth.service - Bluetooth service
   Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2020-07-26 10:44:44 CEST; 1 day 21h ago
     Docs: man:bluetoothd(8)
 Main PID: 359 (bluetoothd)
   Status: "Running"
    Tasks: 1 (limit: 2187)
   CGroup: /system.slice/bluetooth.service
           └─359 /usr/lib/bluetooth/bluetoothd

and “hcitool scan” find my inverter:

Scanning ...
	00:80:25:19:xx:xx	SMA012d SN: 2100423xxx SN2100423xxx

What could be the problem?

My Server Info:
Server Information
-----------------------

Services
	emonhub :	 Active Running
	emoncms_mqtt :	 Active Running
	feedwriter :	 Active Running - sleep 300s 34 feed points pending write
	service-runner :	 Active Running
	emonPiLCD :	 Inactive Dead
	redis-server :	 Active Running
	mosquitto :	 Active Running
	demandshaper :	 Active Running

Emoncms
	Version :	 low-write 10.2.3
	Modules :	 Administration | App v2.1.6 | Backup v2.2.3 | EmonHub Config v2.0.5 | Dashboard v2.0.7 | DemandShaper v1.2.5 | Device v2.0.5 | EventProcesses | Feed | Graph v2.0.9 | Input | Postprocess v2.1.4 | CoreProcess | Schedule | Network Setup v1.0.0 | sync | Time | User | Visualisation | WiFi v2.0.2
	Git :	 
		URL :	 https://github.com/emoncms/emoncms.git
		Branch :	 * stable
		Describe :	 10.2.3

Server
	OS :	 Linux 5.4.51-v7+
	Host :	 tinyrx | tinyrx | (192.168.10.16)
	Date :	 2020-07-28 08:31:34 CEST
	Uptime :	 08:31:34 up 1 day, 21:46,  1 user,  load average: 0.03, 0.06, 0.09

Memory
	RAM :	 Used: 21.78%
		Total :	 976.38 MB
		Used :	 212.67 MB
		Free :	 763.71 MB
	Swap :	 Used: 1.25%
		Total :	 100 MB
		Used :	 1.25 MB
		Free :	 98.75 MB
Write Load Period
Disk
	/ :	 Used: 51.74%
		Total :	 3.92 GB
		Used :	 2.03 GB
		Free :	 1.7 GB
		Write Load :	 n/a
	/boot :	 Used: 21.10%
		Total :	 252.05 MB
		Used :	 53.18 MB
		Free :	 198.86 MB
		Write Load :	 n/a
	/var/opt/emoncms :	 Used: 19.78%
		Total :	 9.98 GB
		Used :	 1.97 GB
		Free :	 7.5 GB
		Write Load :	 n/a
	/_backup :	 Used: 9.75%
		Total :	 28.33 GB
		Used :	 2.76 GB
		Free :	 24.1 GB
		Write Load :	 n/a
	/var/log :	 Used: 3.07%
		Total :	 50 MB
		Used :	 1.54 MB
		Free :	 48.46 MB
		Write Load :	 n/a
	/backup :	 Used: 33.81%
		Total :	 3.48 TB
		Used :	 1.18 TB
		Free :	 2.31 TB
		Write Load :	 n/a

HTTP
	Server :	 Apache/2.4.38 (Raspbian) HTTP/1.1 CGI/1.1 443

MySQL
	Version :	 5.5.5-10.3.22-MariaDB-0+deb10u1
	Host :	 localhost:6379 (127.0.0.1)
	Date :	 2020-07-28 08:31:33 (UTC 02:00‌​)
	Stats :	 Uptime: 164797  Threads: 20  Questions: 843856  Slow queries: 0  Opens: 60  Flush tables: 1  Open tables: 54  Queries per second avg: 5.120

Redis
	Version :	 
		Redis Server :	 5.0.3
		PHP Redis :	 5.0.2
	Host :	 localhost:6379
	Size :	 268 keys (868.61K)
	Uptime :	 1 days
MQTT Server
	Version :	 Mosquitto 1.5.7
	Host :	 localhost:1883 (127.0.0.1)

PHP
	Version :	 7.3.19-1~deb10u1 (Zend Version 3.3.19)
	Modules :	 apache2handlercalendar Core ctype curl date dom v20031129exif fileinfo filter ftp gd gettext hash iconv json v1.7.0libxml mbstring mosquitto v0.4.0mysqli mysqlnd vmysqlnd 5.0.12-dev - 20150407 - $Id: 7cc7cc96e675f6d72e5cf0f267f48e167c2abb23 $openssl pcre PDO pdo_mysql Phar posix readline redis v5.0.2Reflection session shmop SimpleXML sockets sodium SPL standard sysvmsg sysvsem sysvshm tokenizer wddx xml xmlreader xmlwriter xsl Zend OPcache zlib 
Pi
	Model :	 Raspberry Pi 3 Model B+ Rev 1.3 - 1GB (Sony UK)
	Serial num. :	 D618EC32
	CPU Temperature :	 60.69°C
	GPU Temperature :	 61.2°C
	emonpiRelease :	 emonSD-17Oct19
	File-system :	 read-write

Client Information
-----------------------

HTTP
	Browser :	 Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0) Gecko/20100101 Firefox/78.0
	Language :	 de,en-US;q=0.7,en;q=0.3

Window
	Size :	 2012 x 1020

Screen
	Resolution :	 2048 x 1280

When posting server information, please click on ‘copy as markdown’ and post without any further formatting.

The bluetooth service is usually disabled because of shared serial ports.

Is the an emonPi or an emonbase?

If you have updated, you may need to install the bluetooth Python3 module.

Looking at the readme, it suggests

sudo aptitude install bluez python-bluetooth

This may not be correct for python3.

Try (with no warranty :grin:)

sudo apt-get install python3-bluetooth

Yes, I am using an emonbase and onboard bluetooth is disabled. I have connected a second USB dongle. Everything was working years before.

Have you? probably why it is failing.

yes bluetooth Python3 module are installed and was up to date.

oh, sorry python3-bluez was not installed, now it works, thanks for the food for thought.

Thought so. emonhub was upgraded to Python3 and some of the outlying packages were not installed.

Just to confirm, did you just install the bluez package and not the bluetooth one?

I was looking forward to it too soon. Now I get this error message:

2020-07-28 13:09:59,909 ERROR SMASolar bytearray index out of range
2020-07-28 13:09:59,910 ERROR SMASolar [‘Traceback (most recent call last):\n’, ’ File “/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py”, line 219, in read\n self._login_inverter()\n’, ’ File “/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py”, line 89, in _login_inverter\n dictInverterData = SMASolar_library.getInverterDetails(self._btSocket, self._packet_send_counter, self.mylocalBTAddress, self.MySerialNumber)\n’, ’ File “/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py”, line 123, in getInverterDetails\n data = request_data(btSocket, packet_send_counter, mylocalBTAddress, MySerialNumber, 0x58000200, 0x00821E00, 0x008220FF)\n’, ’ File “/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py”, line 284, in request_data\n bluetoothbuffer = read_SMA_BT_Packet(btSocket, packet_send_counter, True, mylocalBTAddress)\n’, ’ File “/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py”, line 63, in read_SMA_BT_Packet\n if waitForPacket and level2Packet.getPacketCounter() != waitPacketNumber:\n’, ’ File “/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py”, line 109, in getPacketCounter\n return self.getTwoByte(26) & 0x7FFF\n’, ’ File “/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py”, line 84, in getTwoByte\n value = self.packet[offset]\n’, ‘IndexError: bytearray index out of range\n’]

I have installed both.

@bwduncan, did you wave your magic wand over the SMA library?

It does appear to have been touched by me, yes. Thanks for testing it!

That error implies a short reply. The code really has no checking that the Bluetooth reply is the correct length. After all, what could we do except log an error?

If this is a persistent problem we can insert some more debugging to see what the data looks like when it fails but I would really expect the interfacer to restart and succeed the next time…

What can I do to support you?
The interfacer restarts but always fails with the same error.

Here’s the log:

2020-07-29 19:23:30,129 ERROR    SMASolar   ['Traceback (most recent call last):\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 219, in read\n    self._login_inverter()\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 89, in _login_inverter\n    dictInverterData = SMASolar_library.getInverterDetails(self._btSocket, self._packet_send_counter, self.mylocalBTAddress, self.MySerialNumber)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 123, in getInverterDetails\n    data = request_data(btSocket, packet_send_counter, mylocalBTAddress, MySerialNumber, 0x58000200, 0x00821E00, 0x008220FF)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 284, in request_data\n    bluetoothbuffer = read_SMA_BT_Packet(btSocket, packet_send_counter, True, mylocalBTAddress)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 63, in read_SMA_BT_Packet\n    if waitForPacket and level2Packet.getPacketCounter() != waitPacketNumber:\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 109, in getPacketCounter\n    return self.getTwoByte(26) & 0x7FFF\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 84, in getTwoByte\n    value = self.packet[offset]\n', 'IndexError: bytearray index out of range\n']
2020-07-29 19:23:36,543 ERROR    SMASolar   bytearray index out of range
2020-07-29 19:23:36,545 ERROR    SMASolar   ['Traceback (most recent call last):\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 219, in read\n    self._login_inverter()\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 89, in _login_inverter\n    dictInverterData = SMASolar_library.getInverterDetails(self._btSocket, self._packet_send_counter, self.mylocalBTAddress, self.MySerialNumber)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 123, in getInverterDetails\n    data = request_data(btSocket, packet_send_counter, mylocalBTAddress, MySerialNumber, 0x58000200, 0x00821E00, 0x008220FF)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 284, in request_data\n    bluetoothbuffer = read_SMA_BT_Packet(btSocket, packet_send_counter, True, mylocalBTAddress)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 63, in read_SMA_BT_Packet\n    if waitForPacket and level2Packet.getPacketCounter() != waitPacketNumber:\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 109, in getPacketCounter\n    return self.getTwoByte(26) & 0x7FFF\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 84, in getTwoByte\n    value = self.packet[offset]\n', 'IndexError: bytearray index out of range\n']
2020-07-29 19:23:42,927 ERROR    SMASolar   bytearray index out of range
2020-07-29 19:23:42,929 ERROR    SMASolar   ['Traceback (most recent call last):\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 219, in read\n    self._login_inverter()\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 89, in _login_inverter\n    dictInverterData = SMASolar_library.getInverterDetails(self._btSocket, self._packet_send_counter, self.mylocalBTAddress, self.MySerialNumber)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 123, in getInverterDetails\n    data = request_data(btSocket, packet_send_counter, mylocalBTAddress, MySerialNumber, 0x58000200, 0x00821E00, 0x008220FF)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 284, in request_data\n    bluetoothbuffer = read_SMA_BT_Packet(btSocket, packet_send_counter, True, mylocalBTAddress)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 63, in read_SMA_BT_Packet\n    if waitForPacket and level2Packet.getPacketCounter() != waitPacketNumber:\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 109, in getPacketCounter\n    return self.getTwoByte(26) & 0x7FFF\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 84, in getTwoByte\n    value = self.packet[offset]\n', 'IndexError: bytearray index out of range\n']
2020-07-29 19:23:49,356 ERROR    SMASolar   bytearray index out of range
2020-07-29 19:23:49,358 ERROR    SMASolar   ['Traceback (most recent call last):\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 219, in read\n    self._login_inverter()\n', '  File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubSMASolarInterfacer.py", line 89, in _login_inverter\n    dictInverterData = SMASolar_library.getInverterDetails(self._btSocket, self._packet_send_counter, self.mylocalBTAddress, self.MySerialNumber)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 123, in getInverterDetails\n    data = request_data(btSocket, packet_send_counter, mylocalBTAddress, MySerialNumber, 0x58000200, 0x00821E00, 0x008220FF)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 284, in request_data\n    bluetoothbuffer = read_SMA_BT_Packet(btSocket, packet_send_counter, True, mylocalBTAddress)\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMASolar_library.py", line 63, in read_SMA_BT_Packet\n    if waitForPacket and level2Packet.getPacketCounter() != waitPacketNumber:\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 109, in getPacketCounter\n    return self.getTwoByte(26) & 0x7FFF\n', '  File "/opt/openenergymonitor/emonhub/src/smalibrary/SMANET2PlusPacket.py", line 84, in getTwoByte\n    value = self.packet[offset]\n', 'IndexError: bytearray index out of range\n']

Did you manage to solve this? I’m having the same trouble after a fresh 10.2.6 and bluez install.

Sorry, unfortunately this problem still exists with me.
With version 10.2.6.

Too bad, good thing I did not overwrite the old 10.2.3 image. I would like to update though, hope someone will be able to fix this bug. @stuart - any idea?

I’ve started a thread to take a look at fixing this, its related to Python3.

@stuart, tag @bwduncan as he has done much of the heavy lifting to get things Python3 compatible. I’m sure he will help, just can’t test the code!

I’ve found the root cause of the problem, just testing out a fix now.

1 Like

Hi @stuart

I’ve fixed the code. Please can you test Sma bugfix by bwduncan · Pull Request #129 · openenergymonitor/emonhub · GitHub

Bruce

2 Likes