openenergymonitor
SMA Solar interface - Python3 changes broke code
Hi, I've just upgraded to the latest OEM release (July 2020) and the SMA Solar code no longer runs. I originally wrote the code and its been running on my old OEM release for the past 5 years!
Looks like there were a lot of Python3 code changes made, have these been tested by anyone against real SMA hardware?
@bwduncan can you help?
2020-09-19 18:03:34,678 ERROR SMASolar bytearray index out of range
2020-09-19 18:03:34,680 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']
5 years! Very impressive.
I don't think we got anyone testing it on real hardware, no. It would be very helpful to get real world testing and I'm happy to help.
I'm busy this weekend but should be able to do a bit of digging at the start of next week. Please can you make sure you turn the logging up to "debug" and paste a complete logfile.
From the snippet you've pasted it would seem to me that the packet is invalid. We're asking for the packet counter as two bytes at a fixed offset but the packet is too short. Probably we should just be throwing this packet away. It might be worth logging some packets to see what we're getting.
Hello, just dropping some comments on here for future debugging needs. My original emon system is dated "emonSD-30Oct18".
The old code is running on Python 2.7.13 and the bluez library.
I've identified the issue in src/smalibrary/SMABluetoothPacket.py
Reverting the code back to
l = len(self.UnescapedArray) - skipendbytes
return self.UnescapedArray[startbyte:l]
fixes the problem
How can we get the base image to have bluetooth installed by default?
These commands need running as part of the base image creation.
sudo apt-get install bluetooth libbluetooth-dev
sudo python3 -m pip install pybluez
There is an install.sh script in the root of this repository, but there is also this https://github.com/openenergymonitor/emonpi/blob/master/docs/SD-card-build.md and I don't know which is used to build the SD card images.
The code appears to be working okay, however I'm now getting a lot of bluetooth timeout errors which I've not seen before.
The code in interfacers/EmonHubSMASolarInterfacer.py seems to be heavily modified to add in restarts and timeouts, but don't know the root reason why these were necessary.
The inverter connects via Bluetooth and logs in, but then hangs/timeouts. If I restart bluetooth service, it works for a bit then stops again.
2020-09-21 13:21:18,973 INFO SMASolar Log into the SMA solar inverter 00:80:25:1D:AC:53
2020-09-21 13:21:18,974 INFO SMASolar Opening bluetooth address 00:80:25:1D:AC:53
2020-09-21 13:21:19,387 INFO SMASolar Connected to SMA inverter named [SN2120051742] with serial number [2120051742] using NodeId=29. Model SB 3000HF-30
2020-09-21 13:21:40,546 ERROR SMASolar Bluetooth Error
@stuartpittaway , did you ever manage to solve this?
I just updated my EmonHub RPi and it logs the one inverter OK (SmaSolar) but can't connect to the other anymore (SmaSolar2).
Converted back to the old EmonHub and both the SMASolar and the SMASolar2 node works again..
The code in interfacers/EmonHubSMASolarInterfacer.py seems to be heavily modified to add in restarts and timeouts, but don't know the root reason why these were necessary.
Can't take the blame for that one, the restart code was added by @k-quigley I just simplified it. The log snippet @stuartpittaway posted doesn't show a timeout or a restart, though. There seems to be very little practical difference between the python2 and python3 versions.
Can either of you provide some debug logs and your configs showing the problem?
If you can apply this patch it should give better tracebacks:
diff --git a/src/interfacers/EmonHubSMASolarInterfacer.py b/src/interfacers/EmonHubSMASolarInterfacer.py
index 0e412ac..68e3c49 100644
--- a/src/interfacers/EmonHubSMASolarInterfacer.py
+++ b/src/interfacers/EmonHubSMASolarInterfacer.py
@@ -134,8 +134,7 @@ class EmonHubSMASolarInterfacer(EmonHubInterfacer):
btSocket.settimeout(10)
except bluetooth.btcommon.BluetoothError as err:
- self._log.error(err)
- self._log.error('Bluetooth error while connecting to %s', inverteraddress)
+ self._log.exception('Bluetooth error while connecting to %s', inverteraddress)
btSocket.close()
errCode = eval(err[0])[0]
if errCode == 16 or errCode == 115:
@@ -304,12 +303,9 @@ class EmonHubSMASolarInterfacer(EmonHubInterfacer):
return c
except bluetooth.btcommon.BluetoothError as err1:
- self._log.error("Bluetooth Error")
- self._log.error(err1)
+ self._log.exception("Bluetooth Error")
self._btSocket = None
except Exception as err2:
- exc_type, exc_value, exc_traceback = sys.exc_info()
- self._log.error(err2)
- self._log.error(repr(traceback.format_exception(exc_type, exc_value, exc_traceback)))
+ self._log.exception("Exception")
self._btSocket = None
Thank you bwduncan - actually I'm running the Interfacer twice as I have two inverters, it worked but I'm not sure it is supposed to support that sort of mistreating.
Anyhow, I will be happy to run the patch and happy to see the updated interfacer work with two inverters :-)
How do I intall the patch? When I run
diff --git a/src/interfacers/EmonHubSMASolarInterfacer.py b/src/interfacers/EmonHubSMASolarInterfacer.py ... ... ...
I get
diff: unrecognized option '--git'
..sorry, but my Python skills are unfortunatly not exactly stellar :-)
The log snippet @stuartpittaway posted doesn't show a timeout or a restart
This is the log from today! It looks like it times out every connection, although I do still get data returned so I've not really looked any further into it.
2022-01-16 10:49:20,127 ERROR SMASolar timed out
2022-01-16 10:49:42,214 ERROR SMASolar Bluetooth Error
2022-01-16 10:49:42,215 ERROR SMASolar timed out
2022-01-16 10:50:04,292 ERROR SMASolar Bluetooth Error
2022-01-16 10:50:04,293 ERROR SMASolar timed out
2022-01-16 10:50:26,453 ERROR SMASolar Bluetooth Error
2022-01-16 10:50:26,454 ERROR SMASolar timed out
2022-01-16 10:50:48,553 ERROR SMASolar Bluetooth Error
2022-01-16 10:50:48,555 ERROR SMASolar timed out
2022-01-16 10:51:10,628 ERROR SMASolar Bluetooth Error
2022-01-16 10:51:10,629 ERROR SMASolar timed out
2022-01-16 10:51:32,714 ERROR SMASolar Bluetooth Error
2022-01-16 10:51:32,715 ERROR SMASolar timed out
2022-01-16 10:51:54,867 ERROR SMASolar Bluetooth Error
2022-01-16 10:51:54,869 ERROR SMASolar timed out
2022-01-16 10:52:17,034 ERROR SMASolar Bluetooth Error
2022-01-16 10:52:17,035 ERROR SMASolar timed out
2022-01-16 10:52:39,258 ERROR SMASolar Bluetooth Error
2022-01-16 10:52:39,259 ERROR SMASolar timed out
2022-01-16 10:52:50,003 ERROR SMASolar Bluetooth Error
2022-01-16 10:52:50,004 ERROR SMASolar timed out
2022-01-16 10:53:12,367 ERROR SMASolar Bluetooth Error
2022-01-16 10:53:12,368 ERROR SMASolar timed out
2022-01-16 10:53:34,433 ERROR SMASolar Bluetooth Error
2022-01-16 10:53:34,434 ERROR SMASolar timed out
2022-01-16 10:53:56,503 ERROR SMASolar Bluetooth Error
2022-01-16 10:53:56,504 ERROR SMASolar timed out
2022-01-16 10:54:18,518 ERROR SMASolar Bluetooth Error
2022-01-16 10:54:18,519 ERROR SMASolar timed out
2022-01-16 10:54:40,631 ERROR SMASolar Bluetooth Error
2022-01-16 10:54:40,632 ERROR SMASolar timed out
2022-01-16 10:55:02,623 ERROR SMASolar Bluetooth Error
2022-01-16 10:55:02,624 ERROR SMASolar timed out
2022-01-16 10:55:24,770 ERROR SMASolar Bluetooth Error
2022-01-16 10:55:24,771 ERROR SMASolar timed out
2022-01-16 10:55:46,889 ERROR SMASolar Bluetooth Error
2022-01-16 10:55:46,890 ERROR SMASolar timed out
My log for SMASolar2 looks the same plus the log also show a rare time out for the SMASolar interfacer. Datalogging for SMASolar seems to work OK, no data at all from SMASolar2.
Do I understand correctly, that the problem most likely stems from an update to EmonHubSMASolarInterfacer.py ? Could I just fetch and run the old EmonHubSMaSolarInterfacer.py software?
Hi Stuart,
I can't find the words "timed out" anywhere in the code. https://github.com/openenergymonitor/emonhub/search?q=timed+out
The string "Bluetooth Error" doesn't appear either https://github.com/openenergymonitor/emonhub/search?q=Bluetooth+Error
Please can you confirm which code you're running? It doesn't look like the code that's in the repository this issue was raised against.
@LykkeGit, There may be a bug in the python3 version of EmonHubSMASolarInterfacer.py (snappy name isn't it!), but python2 was end of life 2 years ago now, so that's why the code was updated. Python 2 is long gone. I admit I seem to be in the minority of people who want things like security updates and bug fixes but if you want to grab the old version and run that under Python 2, it's there for you. It would be interesting to test whether it does actually still work, or whether the bug is in the inverter, or maybe in another part of emonhub.
Bruce
Thank you bwduncan - actually I'm running the Interfacer twice as I have two inverters, it worked but I'm not sure it is supposed to support that sort of mistreating.
No the code is fairly explicit about not knowing how to handle two inverters. Can you share your emonhub.conf?
How do I intall the patch? When I run
diff --git a/src/interfacers/EmonHubSMASolarInterfacer.py b/src/interfacers/EmonHubSMASolarInterfacer.py ... ... ...I get
diff: unrecognized option '--git'..sorry, but my Python skills are unfortunatly not exactly stellar :-)
If you're not accustomed to using git or patch then just make the changes by hand in a text editor. It's pretty easy to make a mess even if you use those tools regularly!
Bruce
I think we agree that everybody will be best served if we can make the new updated PY3 code work :-)
I've made a fresh EmonPi SD-card (10.8.5). I've copied the SMASolar, SMASolar2 and the Emoncmsorg part from the old working EmonHub and set the log to Debug. It seems EmonHub freeze and restarts when the SMASolar2 interfacer tries to read data from the inverter - please see attached logfile.
I have not yet implemented the extra debug in the config file, will do that tonight. emonhub_log.log
@LykkeGit : if you want to run twice the same interfacer, you can duplicate the py file of the interfacer and change the class name. It is very bad practise but should work...for ex: SMAinterfacer.py and SMAinterfacer2.py To finish, declare the new "interfacer" in the init.py
@LykkeGit : if you want to run twice the same interfacer, you can duplicate the py file of the interfacer and change the class name. It is very bad practise but should work...for ex: SMAinterfacer.py and SMAinterfacer2.py To finish, declare the new "interfacer" in the init.py
You don't need to do that... you can run multiple instances of the same interfacer without copying the code. Just give it a unique name in the config e.g. "[[SMASolar2]]" and use the same Type = EmonHubSMASolarInterfacer
Ninja edit: You probably want to give it a unique nodeid too, but you would have to do that if you cloned the code.
I think we agree that everybody will be best served if we can make the new updated PY3 code work :-)
:smile:
I've made a fresh EmonPi SD-card (10.8.5).
Did it work with the fresh install?
I've copied the SMASolar, SMASolar2 and the Emoncmsorg part from the old working EmonHub and set the log to Debug. It seems EmonHub freeze and restarts when the SMASolar2 interfacer tries to read data from the inverter - please see attached logfile.
I have not yet implemented the extra debug in the config file, will do that tonight. emonhub_log.log
Because the code is squashing the details of the exceptions (replacing them with the nondescript "Bluetooth Error" and "timed out") it's really hard to debug. If you can apply that patch, we should be able to see the actual errors. That should give us a place to start.
Just so we're clear: It behaves exactly the same with the old code and the new code?
Bruce
Does it work with each inverter separately? Or does the first inverter always work and the second inverter always fail?
I can't see two invertors working correctly at all - unless you have two bluetooth devices on the PI and 2 different COM ports?
I made the fresh install and removed all but the SMA interfaceres in order to make the test system as simple as possible. The observed behaviour is the same as with the complete install.
I've tried to run the two interfaceres separately and only the first "SMASolar" works. If I comment out SMASolar, SMASolar2 still do not work. It is a little puzzeling, but maybe it has something to do with the SMA BT-mesh, not sure if I can turn that of.
@stuartpittaway , it has worked for many years with one BT/COM on the old EmonHub, but you could well be rigth.
@stuartpittaway , it has worked for many years with one BT/COM on the old EmonHub, but you could well be rigth.
The two interface code instances would be fighting over the COM port - but if you get frequent timeouts that could allow the other interface to get the COM port until it then timesout's and loops
Here is the new log file where I have included the debug code in the interfacer. Hope it provide some clues. emonhub_debug.log
Tried to comment out the working SMASolar interfacer to see if SMASolar2 would start working. Still no luck, same error as in the previous log. Startig to think I have to turn of the SMA BT-network on the inverter..
Ok, same error as I have then....
2022-01-17 19:36:05,790 ERROR SMASolar2 Bluetooth Error
Traceback (most recent call last):
File "
OK that's great, thank you both.
@LykkeGit it looks like you are using the default bluetooth address in the example configuration, not the actual bluetooth address of your device. Did you follow the instructions to find the correct address? Please share your emonhub.conf.
Did you follow the instructions to find the correct address?
I can not remember, think I searched for BT device and manually added the adresses. The BT adresses have been like this of maybe 7-8 years.
My emonhub.conf is the standard with the addition of:
[[SMASolar]] Type = EmonHubSMASolarInterfacer [[[init_settings]]] inverteraddress= 00:80:25:25:DC:BF # West inverterpincode = 0000 timeinverval = 10 nodeid = 29 [[[runtimesettings]]] pubchannels = ToEmonCMS,
[[SMASolar2]] Type = EmonHubSMASolarInterfacer [[[init_settings]]] inverteraddress= 00:80:25:25:EA:5C # Øst inverterpincode = 0000 timeinverval = 10 nodeid = 30 [[[runtimesettings]]] pubchannels = ToEmonCMS,
OK my bad I didn't read the mac address closely enough. Sorry!
Can we try seeing what the device is sending? If you set packettrace = 1 in the init_settings section, you should get lots of debug log messages.
Sorry, small problem: logged onto the inverters w. SMA Explorer and I had to update password. Think EmonHub is back to normal again though. Shouldn't mess with two things at the same time - sorry :-)
Please find the requested output attached.
Do you think it may help to put the two inverteres on separate SMA BT-mesh networks? Tomorrow I can try and change the network ID on one of the inverters, think there is a switch on the inverter.
OK, so it's clearly receiving data. Please can we try something really simple and just set the bluetooth timeout to a more sensible value? I would suggest 60s or even 600s. It's on line 134 and looks like this:
btSocket.settimeout(10)
Change it to 600.