kbialek / deye-inverter-mqtt

Reads Deye solar inverter metrics and posts them over MQTT
Apache License 2.0
227 stars 50 forks source link

Deye inverter SUN600G3-EU-230 at (and tcp) reading stopped working #206

Open MarcErl opened 1 week ago

MarcErl commented 1 week ago

I probably automatically got a new firmware for my deye inverter two days ago or so.. Before that I had a working configuration with the AT protocol since ~ one year. It suddenly stopped working:-( Deye has written something with security fix on their homepasge..

Does anyone have this combination still working or an idea how to fix?

My configuration:

DEYE_LOGGER_IP_ADDRESS=xxx (of course the correct one)
DEYE_LOGGER_SERIAL_NUMBER=xxx (of course the correct one)
DEYE_LOGGER_PROTOCOL=at

MQTT_HOST=localhost
MQTT_PORT=1883
MQTT_USERNAME=xxx
MQTT_PASSWORD=xxx
MQTT_TOPIC_PREFIX=deye

LOG_LEVEL=DEBUG
DEYE_METRIC_GROUPS=string

Tried several configurations:

1. DEYE_LOGGER_PROTOCOL=at + default port --> connection timeouts

...
2024-10-15 18:29:27,008 - DeyeConnectorFactory - INFO - Creating Modbus/AT Logger connector
2024-10-15 18:29:27,012 - DeyeProcessorFactory - INFO - Feature "Report metrics over MQTT": enabled
2024-10-15 18:29:27,013 - DeyeProcessorFactory - INFO - Feature "Set inverter time once online": disabled
2024-10-15 18:29:27,013 - DeyeProcessorFactory - INFO - Feature "Time-of-use configuration over MQTT": disabled
2024-10-15 18:29:27,014 - DeyeActivePowerRegulationEventProcessor - ERROR - Active power regulation sensor not found. Enable appropriate settings metric group.
2024-10-15 18:29:27,015 - DeyeProcessorFactory - INFO - Feature "Active power regulation over MQTT": disabled
2024-10-15 18:29:27,052 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:27,061 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:28,059 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r1, m1), 'b'deye1/status'', ... (6 bytes)
2024-10-15 18:29:28,060 - DeyeMqttClient - INFO - Successfully connected to MQTT Broker located at localhost:1883
2024-10-15 18:29:28,063 - DeyeDaemon - DEBUG - Starting executing the runner at intervals of 60 seconds
...
2024-10-15 18:29:50,066 - DeyeDaemon - DEBUG - Invoking action
2024-10-15 18:29:50,067 - DeyeInverterState - INFO - Reading start
2024-10-15 18:29:50,068 - DeyeInverterState - INFO - Reading registers [metrics group: {'string'}, range: 003c-0074]
2024-10-15 18:29:50,069 - DeyeAtConnector - DEBUG - Sending AT command: b'WIFIKIT-214028-READ'
2024-10-15 18:29:51,171 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:51,231 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:51,234 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:52,173 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:53,175 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:53,243 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:53,247 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:54,177 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:55,179 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:55,180 - DeyeAtConnector - WARNING - Too many connection timeouts
2024-10-15 18:29:55,180 - DeyeAtConnector - DEBUG - Sending AT command: b'+ok'
2024-10-15 18:29:55,258 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:55,263 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:55,282 - DeyeAtConnector - DEBUG - Sending AT command: b'AT+INVDATA=8,0103003c003945d4\n'
 2024-10-15 18:29:57,275 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:57,278 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:57,385 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:29:58,387 - DeyeAtConnector - DEBUG - Connection response timeout
^C2024-10-15 18:29:58,697 - DeyeDaemon - DEBUG - Stopping the runner
2024-10-15 18:29:59,288 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:29:59,291 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:29:59,389 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:30:00,391 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:30:01,301 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:30:01,304 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:30:01,393 - DeyeAtConnector - DEBUG - Connection response timeout
2024-10-15 18:30:01,394 - DeyeAtConnector - WARNING - Too many connection timeouts
2024-10-15 18:30:01,395 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-10-15 18:30:01,396 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-10-15 18:30:01,396 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye1/logger_status', value: 'offline'
2024-10-15 18:30:01,397 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m2), 'b'deye1/logger_status'', ... (7 bytes)
2024-10-15 18:30:01,399 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 2)
2024-10-15 18:30:01,400 - DeyeMqttClient - INFO - Logger is offline
2024-10-15 18:30:01,401 - DeyeInverterState - INFO - Reading completed
2024-10-15 18:30:01,402 - DeyeDaemon - DEBUG - Invocation loop stopped

2. DEYE_LOGGER_PROTOCOL=tcp + default port --> recognizes an AT response

...
2024-10-15 18:08:39,302 - DeyeConnectorFactory - INFO - Creating Modbus/TCP Logger connector
2024-10-15 18:08:39,306 - DeyeProcessorFactory - INFO - Feature "Report metrics over MQTT": enabled
2024-10-15 18:08:39,307 - DeyeProcessorFactory - INFO - Feature "Set inverter time once online": disabled
2024-10-15 18:08:39,308 - DeyeProcessorFactory - INFO - Feature "Time-of-use configuration over MQTT": disabled
2024-10-15 18:08:39,309 - DeyeActivePowerRegulationEventProcessor - ERROR - Active power regulation sensor not found. Enable appropriate settings metric group.
2024-10-15 18:08:39,310 - DeyeProcessorFactory - INFO - Feature "Active power regulation over MQTT": disabled
2024-10-15 18:08:39,335 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:08:39,338 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:08:40,339 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r1, m1), 'b'deye1/status'', ... (6 bytes)
2024-10-15 18:08:40,341 - DeyeMqttClient - INFO - Successfully connected to MQTT Broker located at localhost:1883
2024-10-15 18:08:40,343 - DeyeDaemon - DEBUG - Starting executing the runner at intervals of 60 seconds
2024-10-15 18:08:41,349 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:08:41,352 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
...
2024-10-15 18:08:59,347 - DeyeDaemon - DEBUG - Invoking action
2024-10-15 18:08:59,348 - DeyeInverterState - INFO - Reading start
2024-10-15 18:08:59,348 - DeyeInverterState - INFO - Reading registers [metrics group: {'string'}, range: 003c-0074]
2024-10-15 18:08:59,356 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000594272e90200000000000000000000000000000103003c003945d4f615
2024-10-15 18:08:59,361 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: 41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a
2024-10-15 18:08:59,364 - DeyeModbusTcp - ERROR - AT response detected. Try switching to 'AT' protocol. Set 'DEYE_LOGGER_PROTOCOL=at' and remove DEYE_LOGGER_PORT from your config
2024-10-15 18:08:59,366 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-10-15 18:08:59,367 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-10-15 18:08:59,368 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye1/logger_status', value: 'offline'
2024-10-15 18:08:59,371 - DeyeMqttPublisher - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2024-10-15 18:08:59,373 - DeyeInverterState - INFO - Reading completed
2024-10-15 18:08:59,473 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:08:59,476 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:08:59,477 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m2), 'b'deye1/logger_status'', ... (7 bytes)
2024-10-15 18:08:59,478 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 2)
2024-10-15 18:09:01,485 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:09:01,489 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:09:03,499 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
2024-10-15 18:09:03,501 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-10-15 18:09:05,511 - paho.mqtt.client - DEBUG - Sending CONNECT (u1, p1, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-3916579417'
...

3. Combination of DEYE_LOGGER_PROTOCOL=at with port 8899 --> not working (like at and default port)

Bhoft commented 1 week ago

Had the same after an automatic firmware update the at mode isn't accessible any more. You have to switch to the TCP mode.

MarcErl commented 1 week ago

Hmm, I tried to do so. Maybe I mixed up the config parameters and/or the inverter was already in standby. I'll retry tomorrow or the day after tomorrow (short days already). Just to be sure: You only set "DEYE_LOGGER_PROTOCOL=tcp" or also a specific port?

kbialek commented 1 week ago

Remove DEYE_LOGGER_PORT from the config.

MarcErl commented 1 week ago

Hi, I tried again to switch to tcp without setting a port in the config. Still with the following output:

2024-10-16 08:58:33,143 - DeyeDaemon - DEBUG - Invoking action
2024-10-16 08:58:33,144 - DeyeInverterState - INFO - Reading start
2024-10-16 08:58:33,145 - DeyeInverterState - INFO - Reading registers [metrics group: {'string'}, range: 003c-0074]
2024-10-16 08:58:33,150 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000594272e90200000000000000000000000000000103003c003945d4f615
2024-10-16 08:58:33,257 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: 41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a
2024-10-16 08:58:33,259 - DeyeModbusTcp - ERROR - AT response detected. Try switching to 'AT' protocol. Set 'DEYE_LOGGER_PROTOCOL=at' and remove DEYE_LOGGER_PORT from your config
2024-10-16 08:58:33,261 - DeyeInverterState - DEBUG - Data readiness observations: []
2024-10-16 08:58:33,262 - DeyeInverterState - DEBUG - Data readiness check result: True
2024-10-16 08:58:33,263 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye1/logger_status', value: 'offline'
2024-10-16 08:58:33,264 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m3), 'b'deye1/logger_status'', ... (7 bytes)
2024-10-16 08:58:33,267 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 3)
2024-10-16 08:58:33,269 - DeyeMqttClient - INFO - Logger is offline
2024-10-16 08:58:33,270 - DeyeInverterState - INFO - Reading completed

The system is producing energy now and I can read out values via solarman online. I remember that this inverter had a problem last year that tcp did not work anymore and that's why at-protocol was added to this project. But since @Bhoft has written that it works with tcp I'm now a bit confused.

P.S.: I recognized that I selected metric group string instead of micro and changed it - but that has no effect.

Bhoft commented 1 week ago

My Inverter (SUN-M160G4-EU-Q0) updated from MW3_16U_5406_1.59 to MW3_SSL_5408_1.0B on the 26. August 2024. Since that the AT mode was blocked. I blocked the internet access afterwards for the inverter.

I had the assumtion that only the AT mode was disabled as it was also mentioned here https://github.com/kbialek/deye-inverter-mqtt/issues/193#issuecomment-2317308916 But this was a older firmware version MW3_SSL_5408_1.0B (SUNxG3).

It could be that the have updated their firmware and blocked the connection for the TCP mode as well. Then your only chance to get to your inverter connected to the dummy cloud. Hopefully this is still working...

You can find more information about that here: https://github.com/Hypfer/deye-microinverter-cloud-free

Its also code which runs in docker and is getting then the information of the inverter directly. But as far as i remember not that often as the code from kbialek as the inverter sends it from time to time. But at least that would be better than nothing.

Bhoft commented 1 week ago

The page you meant which mention the security fix is this one https://www.deyeinverter.com/news/company-news/customer-information-security-update-for-deye-micro-inverters.html Which is rather old (Feb 2024) and didn't mention the firmware versions which have been automatically installed on your and my inverter so its an older issue.

Sadly i can't find anything yet mentioning your firmware version.

Another thing which might still work is "dSolarLite". I just saw that recently here and see no "doesn't work any more" postings. https://diysolarforum.com/threads/dsolar-a-home-solar-power-plant-monitoring-system-using-deye-epever-victron-smartshunt-equipment.60193/#post-1233632

In the video he hasn't used any special port only "modbus address= 1" what ever that means. https://youtu.be/dVju-n63Wug?t=58

So don't know if that still works or whatever method he uses to connect to the converter (maybe they just changed the at port from 8899/48899 to 1 :P ) Sadly its not open source so we can't look into it.

What i also just read here in a german forum is that someone requested a firmware downgrade via email contact to deye just one month ago. https://www.photovoltaikforum.com/thread/235467-kein-zugriff-mehr-auf-deye-wechselrichter/

I didn't knew that this firmware downgrade was even possible via request. So maybe thats your chance to get access again.

kbialek commented 1 week ago

@MarcErl you may also consider downgrading the firmware on your own. Check out this project https://github.com/dasrecht/deye-firmware

MarcErl commented 1 week ago

Thanks guys - I'll try out several things the next days. It needs daylight for the inverter to be online...

MarcErl commented 1 week ago

Okay, I have an update. After following further hints in www, I found this (adopted) project: https://github.com/dmaj/deye-controller/tree/master with the hint that some registers have been changed for this inverter type (but for me the relevant look the same). I called that script with

def print_reg(register):
    print(register.description, register.format(), register.suffix)

if __name__ == '__main__':
  from deye_controller.modbus.sun_x_g3_registers import SunXG3Registers, SunXG3RegistersWrite
  from pysolarmanv5 import PySolarmanV5

  inv = PySolarmanV5('192.168.xxx.xxx', xxxxxxxx)
  print_reg(SunXG3Registers.ACActivePower(inv))
  inv.disconnect()

and I got:

ac_active_power 26.0 W

(26 W is plausible, same as via solarman web). But I also very often get a timeout :-(

Traceback (most recent call last):
  File "/home/openhabian/deye-controller/read_single.py", line 12, in <module>
    print_reg(SunXG3Registers.ACActivePower(inv))
  File "/home/openhabian/deye-controller/deye_controller/modbus/sun_x_g3_registers.py", line 136, in __init__
    resACActivePower = inv.read_holding_registers(self.address, self.len)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 591, in read_holding_registers
    modbus_values = self._get_modbus_response(mb_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 460, in _get_modbus_response
    mb_response_frame = self._send_receive_modbus_frame(mb_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 427, in _send_receive_modbus_frame
    v5_response_frame = self._send_receive_v5_frame(v5_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 285, in _send_receive_v5_frame
    v5_response = self._data_queue.get(timeout=self.socket_timeout)
  File "/home/openhabian/.pyenv/versions/3.10.13/lib/python3.10/multiprocessing/queues.py", line 114, in get
    raise Empty
_queue.Empty

So - modbus via tcp seems to be possible but something is special with this inverter. Any chance to get it handled in deye-inverter-mqtt?

kbialek commented 1 week ago

I looked at pysolarmanv5 source code. I did not spot any logical difference in the communication protocol. Could you run your test with inv = PySolarmanV5('192.168.xxx.xxx', xxxxxxxx, verbose=True) ? Or even better, capture the network traffic with Wireshark?

MarcErl commented 1 week ago

I need to set up wireshark - until that with verbose=True:

Success:

DEBUG:pysolarmanv5:Socket setup completed... <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.178.71', 55354), raddr=('192.168.178.90', 8899)>
DEBUG:pysolarmanv5:[xxxxxxxxxx] SENT: a5 17 00 10 45 f7 00 59 42 72 e9 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 56 00 02 24 1b f6 15
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: 41 54 2b 59 5a 43 4d 50 56 45 52 3d 4d 57 33 5f 31 36 55 5f 35 34 30 38 5f 35 2e 30 42 2d 53 0d 0a 0d 0a
DEBUG:pysolarmanv5:[xxxxxxxxxx] RECD: a5 17 00 10 15 f7 5d 59 42 72 e9 02 01 40 d0 05 00 3b 11 00 00 c6 b7 0c 67 01 03 04 00 28 00 00 7a 3b bf 15
ac_active_power 4.0 W

With timeout:

DEBUG:pysolarmanv5:Socket setup completed... <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.178.71', 34542), raddr=('192.168.178.90', 8899)>
DEBUG:pysolarmanv5:[xxxxxxxxxx] SENT: a5 17 00 10 45 a7 00 59 42 72 e9 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 56 00 02 24 1b a6 15
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: 41 54 2b 59 5a 43 4d 50 56 45 52 3d 4d 57 33 5f 31 36 55 5f 35 34 30 38 5f 35 2e 30 42 2d 53 0d 0a 0d 0a
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 10 03 e8 00 14 59 ad
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 10 00 c8 00 14 58 23
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 10 03 e8 00 14 59 ad
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 10 00 c8 00 14 58 23

... repeated many times ...

DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 10 03 e8 00 14 59 ad
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 0a 00 00 00 00 00 00 00 00 00 00 be 9c
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 06 f3 ce 87 12 00 01 9e 20
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:Got exception when receiving frame
Traceback (most recent call last):
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 285, in _send_receive_v5_frame
    v5_response = self._data_queue.get(timeout=self.socket_timeout)
  File "/home/openhabian/.pyenv/versions/3.10.13/lib/python3.10/multiprocessing/queues.py", line 114, in get
    raise Empty
_queue.Empty
Traceback (most recent call last):
  File "/home/openhabian/deye-controller/read_single.py", line 12, in <module>
    print_reg(SunXG3Registers.ACActivePower(inv))
  File "/home/openhabian/deye-controller/deye_controller/modbus/sun_x_g3_registers.py", line 136, in __init__
    resACActivePower = inv.read_holding_registers(self.address, self.len)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 591, in read_holding_registers
    modbus_values = self._get_modbus_response(mb_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 460, in _get_modbus_response
    mb_response_frame = self._send_receive_modbus_frame(mb_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 427, in _send_receive_modbus_frame
    v5_response_frame = self._send_receive_v5_frame(v5_request_frame)
  File "/home/openhabian/deye-controller/pysolarmanv5.py", line 285, in _send_receive_v5_frame
    v5_response = self._data_queue.get(timeout=self.socket_timeout)
  File "/home/openhabian/.pyenv/versions/3.10.13/lib/python3.10/multiprocessing/queues.py", line 114, in get
    raise Empty
_queue.Empty
kbialek commented 1 week ago

I see that pysolarmanv5 gets this same response as my service does. Look at these fragments of your logs

Both get this data from the logger 41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a Actually that's text "AT+YZCMPVER=MW3_16U_5408_5.0B-S"

However, according to your logs, pysolarmanv5 also got this valid response

DEBUG:pysolarmanv5:[xxxxxxxxxx] RECD: a5 17 00 10 15 f7 5d 59 42 72 e9 02 01 40 d0 05 00 3b 11 00 00 c6 b7 0c 67 01 03 04 00 28 00 00 7a 3b bf 15
  1. Did you remove any lines from the logs before posting?
  2. No need to capture the traffic with Wireshark anymore. The logs are enough.
MarcErl commented 1 week ago

Did you remove any lines from the logs before posting?

Nope, looks that it sends both directly after each other...

kbialek commented 1 week ago

Okay, maybe there is an option to turn that "AT+..." message off in the inverter's config. Did you check it?

Take a look at:

  1. http:///config.html
  2. http:///config_hide.html
MarcErl commented 1 week ago

Unfortunately I can not find any possibility to switch it of in config or hidden config.

image

And sometimes also other issues, like below.

DEBUG:pysolarmanv5:[xxxxxxxxxx] SENT: a5 17 00 10 45 f7 00 59 42 72 e9 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 56 00 02 24 1b f6 15
DEBUG:pysolarmanv5:[xxxxxxxxxx] V5_MISMATCH: 41 54 2b 59 5a 43 4d 50 56 45 52 3d 4d 57 33 5f 31 36 55 5f 35 34 30 38 5f 35 2e 30 42 2d 53 0d 0a 0d 0a
DEBUG:pysolarmanv5:[xxxxxxxxxx] RECD: a5 17 00 10 15 f7 1b 59 42 72 e9 02 01 3b ea 05 00 89 04 00 00 9b 7c 0d 67 01 03 04 00 e6 00 00 1b c4 56 15 aa 03 06 f3 ce 87 12 00 01 9e 20 aa 03 26 00 04 01 00 02 01 32 32 31 32 31 38 32 34 37 37 00 01 00 00 12 0c 07 00 01 01 01 16 12 16 00 00 17 70 00 00 02 01 d3 1e
DEBUG:pysolarmanv5:frame_len does not match payload_len.

It seems they have somehow damaged the protocol. Probably it doesn't make sense to try to work around that behaviour. Maybe I really ask them to downgrade the inverter - via config page it doesn't execute a downgrade (also read that somewhere). Other possibility is to get the values via cloud - but...

kovaga commented 1 week ago

Guys, is there a way to use the standard modbus polling utilities in Linux e.g. mbpoll to poll the deye inverter and include the serial number for auth ? Had my "Deye SUN-M200G4-EU-Q0" connected yday, and trying to find a way to read the data directly of it, without using the mqtt.

MarcErl commented 1 week ago

I found a new (?) addon for OpenHab (LswLogger Binding [Sofar/Omnik/IE wifi/eth stick for SolarmanPV]). With this I get my values again. I've not yet analyzed what it is doing different. In case of interest, I can collect a Wireshark trace. Otherwise I'm now fine with that (after I've blocked the internet for my inverter...).

kbialek commented 1 week ago

@MarcErl Please do capture the traffic

MarcErl commented 1 week ago

No problem! Two files: One when starting the addon "thing" and one a bit later where the value for total output value changes at the end (maybe others too). Openhab AddOn.zip

kbialek commented 1 week ago

@MarcErl Did you by any chance set the Logger Modbus Address to 0xAA? :thinking:

I see such Modbus response frames in the wireshark dump:

aa03260004010002013232313231383234373700010000120c07000101011612160000177000000201d31e

The first byte is the Logger Modbus Address. Usually it's 0x01, but here it's 0xAA. deye-inverter-mqtt assumes it's set to 0x01. I'm considering making it configurable now.

MarcErl commented 1 week ago

I don’t see any possibility to change it. But if I‘m the only one having this issue, you don’t need to adapt it - I can also live with the OpenHAB addon.

Kolbi commented 6 days ago

Just for documentation link to your used OpenHAB addon: https://github.com/ptrbojko/openhab-lsw4inverter-binding

MaPollas commented 6 days ago

I don’t see any possibility to change it. But if I‘m the only one having this issue, you don’t need to adapt it - I can also live with the OpenHAB addon.

Hi there

i have exactly the same problem as MarcErl.

my setup: inverter 1: DEYE SUN-W600 logger firmware version: MW3_SSL_5408_1.0B no problem

inverter 2: DEYE SUN-M80G3 logger firmware version: MW3_16U_5408_5.0B-S problem since: 2024-10-10

config:

DEYE_LOGGER_COUNT 2
DEYE_METRIC_GROUPS micro
DEYE_FEATURE_MULTI_INVERTER_DATA_AGGREGATOR true

DEYE_LOGGER_2_IP_ADDRESS 192.168.100.76
DEYE_LOGGER_2_PROTOCOL at
DEYE_LOGGER_2_SERIAL_NUMBER xxxx

DEYE_LOGGER_1_PROTOCOL tcp
DEYE_LOGGER_1_SERIAL_NUMBER yyyy
DEYE_LOGGER_1_IP_ADDRESS 192.168.100.105

error: (repeatedly)

2024-10-21 14:49:41,327 - DeyeInverterState - INFO - [2] Reading registers [metrics group: {'micro'}, range: 0050-0053]                     
2024-10-21 14:49:46,432 - DeyeAtConnector - WARNING - [2] Too many connection timeouts                                                      
2024-10-21 14:49:52,638 - DeyeAtConnector - WARNING - [2] Too many connection timeouts                                                      
2024-10-21 14:49:52,638 - DeyeInverterState - INFO - [2] Reading registers [metrics group: {'micro'}, range: 0054-0057]                     
2024-10-21 14:49:57,744 - DeyeAtConnector - WARNING - [2] Too many connection timeouts                                                      
2024-10-21 14:50:03,950 - DeyeAtConnector - WARNING - [2] Too many connection timeouts                                                      
2024-10-21 14:50:03,951 - DeyeInverterState - INFO - [2] Reading registers [metrics group: {'micro'}, range: 0058-005b]                     
2024-10-21 14:50:09,055 - DeyeAtConnector - WARNING - [2] Too many connection timeouts 

@kbialek : would be great if you could make the Logger Modbus Address configureable

kbialek commented 5 days ago

@MarcErl

But if I‘m the only one having this issue, you don’t need to adapt it - I can also live with the OpenHAB addon.

Maybe we can learn something if you don't mind :slightly_smiling_face:

Do you have an external relay, e.g. Deye SUN-MI-RELAY-01 connected to your microinverter?

MarcErl commented 5 days ago

Ah, yes that is true😳

kbialek commented 4 days ago

Let me summarize my findings.

Facts

  1. Openhab plugin sends Modbus requests to the microinverter at port 8899/tcp.
  2. Openhab plugin does not receive responses, but gets a lot of timeouts instead.
  3. Relay is connected to the microinverter.
  4. Relay uses Modbus to communicate with the microinverter on port 8899/tcp
  5. Wireshark dumps contain Modbus responses only, that are sent from Modbus device having address 0xAA.

Assumptions

  1. The microinverter is capable to communicate with only one client a time.
  2. The microinverter accepts more than one connection at port 8899/tcp.
  3. The microinverter publishes Modbus responses to all connected clients. This is probably a bug in the microinverter's firmware. Probably it uses shared outbound data buffer for all established connections.

Consequences

  1. Openhab plugin receives Modbus resposes that are dedicated to the Relay.
  2. Openhab plugin interprets Modbus responses and converts them to the metrics. This interpretation might be wrong and is not trustwothy, as the response does not contain register addresses.
  3. deye-inverter-mqtt ignores unexpected Modbus responses, thus does not show any data in this setup.

Here is a docker image ghcr.io/kbialek/deye-inverter-mqtt:2024.10.1-beta-1 that use 0xAA Modbus address instead of 0x01 in case you want to play around with it. Maybe it will somehow work together with the relay. In general I recommend to reduce the read interval to minimize the risk of timeout.

MarcErl commented 2 days ago

Thank you for the test image. Today I had a little time to try it out. Unfortunately without success. And my inverter stopped to deliver power. I can not say if that really was related. I thought that it maybe disturbed the communication between relay and inverter. But it was not reproducible and I didn't check if it was ok before the first try. At least the daily production was some kWh. I didn't had the chance to make a wireshark trace and unfortunately debug level only info. Maybe hard for me the next days to catch sunlight for more tries..

2024-10-24 13:33:37,198 - DeyeInverterState - INFO - Reading start
2024-10-24 13:33:37,199 - DeyeInverterState - INFO - Reading registers [metrics group: {'micro'}, range: 003c-0074]
2024-10-24 13:33:37,320 - DeyeModbusTcp - ERROR - AT response detected. Try switching to 'AT' protocol. Set 'DEYE_LOGGER_PROTOCOL=at' and remove DEYE_LOGGER_PORT from your config
2024-10-24 13:33:37,328 - DeyeMqttClient - INFO - Logger is offline
2024-10-24 13:33:37,328 - DeyeInverterState - INFO - Reading completed
kbialek commented 2 days ago

@MarcErl Thanks for checking.

I've realized that I overlooked one important detail. In the Wireshark logs it's visible that Deye simplified the communication protocol. They removed their proprietary wrapper frame. I will call it slimtcp protocol as for now.

So here is another beta image ghcr.io/kbialek/deye-inverter-mqtt:2024.10.1-beta-2 that offers you two things:

  1. You can set DEYE_LOGGER_PROTOCOL=slimtcp to activate simplified protocol
  2. You can add DEYE_LOGGER_MODBUS_ADDRESS=170 to use 0xAA Modbus address (170 == 0xAA)

Please try this new protocol with Modbus address 1 and 170.

videejay commented 1 day ago

@kbialek I tried the beta-2 with those settings and I get:

2024-10-26 10:23:42,884 - DeyeInverterState - INFO - Reading start 2024-10-26 10:23:42,884 - DeyeInverterState - INFO - Reading registers [metrics group: {'string'}, range: 003c-0074] 2024-10-26 10:23:42,889 - DeyeTcpConnector - INFO - Re-connected to socket on IP 192.168.XXX.YYY 2024-10-26 10:23:42,889 - DeyeTcpConnector - DEBUG - Request frame: aa03003c00395c0f 2024-10-26 10:23:42,892 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: 41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a 2024-10-26 10:23:42,893 - DeyeModbus - ERROR - Modbus frame is too short 2024-10-26 10:23:42,894 - DeyeInverterState - DEBUG - Data readiness observations: [] 2024-10-26 10:23:42,895 - DeyeInverterState - DEBUG - Data readiness check result: True 2024-10-26 10:23:42,895 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/logger_status', value: 'offline' 2024-10-26 10:23:42,896 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m4), 'b'deye/logger_status'', ... (7 bytes) 2024-10-26 10:23:42,898 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 4) 2024-10-26 10:23:42,898 - DeyeMqttClient - INFO - Logger is offline 2024-10-26 10:23:42,899 - DeyeInverterState - INFO - Reading completed 2024-10-26 10:24:28,944 - paho.mqtt.client - DEBUG - Sending PINGREQ 2024-10-26 10:24:28,946 - paho.mqtt.client - DEBUG - Received PINGRESP

My firmware version is also:MW3_16U_5408_5.0B-S on a SUN600G3-EU-230 in combination with the RELAY-01

TCP Server settings are: image

Container settings are:

environment:

  • DEYE_LOGGER_IP_ADDRESS=192.168.XXX.YYY
  • DEYE_LOGGER_SERIAL_NUMBER=ZZZZ
  • MQTT_HOST=192.168.XXX.AAA
  • MQTT_TOPIC_PREFIX=deye
  • LOG_LEVEL=DEBUG
  • DEYE_DATA_READ_INTERVAL=60
  • DEYE_METRIC_GROUPS=string
  • DEYE_LOGGER_PROTOCOL=slimtcp
  • DEYE_LOGGER_MODBUS_ADDRESS=170

Did someone succeed in a successful downgrade?

Edit: Looks like that the response i got is the firmware version:

41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a
=> AT+YZCMPVER=MW3_16U_5408_5.0B-S
videejay commented 3 hours ago

Tryied also DEYE_LOGGER_MODBUS_ADDRESS=1 without success:

2024-10-27 12:51:34,294 - DeyeInverterState - INFO - Reading start 2024-10-27 12:51:34,294 - DeyeInverterState - INFO - Reading registers [metrics group: {'string'}, range: 003c-0074] 2024-10-27 12:51:34,298 - DeyeTcpConnector - DEBUG - Request frame: 0103003c003945d4 2024-10-27 12:51:34,407 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: 41542b595a434d505645523d4d57335f3136555f353430385f352e30422d530d0a0d0a 2024-10-27 12:51:34,408 - DeyeModbus - ERROR - Modbus frame is too short 2024-10-27 12:51:34,408 - DeyeInverterState - DEBUG - Data readiness observations: [] 2024-10-27 12:51:34,409 - DeyeInverterState - DEBUG - Data readiness check result: True 2024-10-27 12:51:34,409 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/logger_status', value: 'offline' 2024-10-27 12:51:34,412 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m2), 'b'deye/logger_status'', ... (7 bytes) 2024-10-27 12:51:34,418 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 2) 2024-10-27 12:51:34,421 - DeyeMqttClient - INFO - Logger is offline 2024-10-27 12:51:34,424 - DeyeInverterState - INFO - Reading completed

videejay commented 1 hour ago

Just an update for everyone following this. I found https://github.com/dmaj/deye-controller which gave me the possibility to read data out of the inverter. It's using PvSolarman5 as library. I don't see if it is possible to add this to this project too. I didn't find any other project offering the data via mqtt using PvSolarman5 yet.