search

kbialek / deye-inverter-mqtt

Reads Deye solar inverter metrics and posts them over mqtt
Apache License 2.0
210 stars 48 forks source link

Error. Modbus device address does not match #187

Open karolisju opened 1 month ago

karolisju commented 1 month ago

Hello, help is appreciated or some hint where to look.

Hardware :

Software :

For a couple of days trying to figure out where is a problem, errors:

  1. “DeyeMqttPublisher - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.” (randomly)
  2. “DeyeModbusTcp - ERROR - Modbus device address does not match.”
  3. “DeyeSetTimeProcessor - WARNING - Failed to set logger time”

I guess the issue/error is related to writing inverter settings. First of all tried the function timeofuse (according to documentation), but there are no errors and nothing changes in the inverter. loglevel=debug

After enabling the feature flag “DEYE_FEATURE_SET_TIME=true” saw errors that Time could not be set and I guess due to Modbus error. Tried different protocols tcp and at (Inverter metrics receiving over MQTT)

Config.env

DEYE_LOGGER_IP_ADDRESS=10.0.1.54
DEYE_LOGGER_PORT=8899
DEYE_LOGGER_SERIAL_NUMBER=2799835885
DEYE_LOGGER_PROTOCOL=tcp
DEYE_LOGGER_MAX_REG_RANGE_LENGTH=256

MQTT_HOST=10.0.1.200
MQTT_PORT=1883
MQTT_TOPIC_PREFIX=deye

LOG_LEVEL=DEBUG
LOG_STREAM=STDOUT
PLUGINS_DIR=plugins
PLUGINS_ENABLED=deye_plugin_sample,deye_plugin_custom
DEYE_DATA_READ_INTERVAL=60
DEYE_METRIC_GROUPS=deye_sg04lp3,deye_sg04lp3_battery,deye_sg04lp3_ups,deye_sg04lp3_timeofuse,deye_sg04lp3_generator,settings

DEYE_FEATURE_MQTT_PUBLISHER=true
DEYE_FEATURE_TIME_OF_USE=true
DEYE_FEATURE_ACTIVE_POWER_REGULATION=true
DEYE_FEATURE_SET_TIME=true

Logs:


deye-inverter-mqtt-py3.12) (base) @Karolis-MacBook-Air deye-original % sh local-run.sh
[local-run] Using bash
2024-07-08 22:01:00,090 - DeyeDaemon - INFO - Please help me build the list of compatible inverters. https://github.com/kbialek/deye-inverter-mqtt/issues/41
2024-07-08 22:01:00,093 - DeyePluginLoader - INFO - Loading plugin: 'deye_plugin_sample'
2024-07-08 22:01:00,093 - DeyeConnectorFactory - INFO - Creating Modbus/TCP Logger connector
2024-07-08 22:01:00,093 - DeyeProcessorFactory - INFO - Feature "Report metrics over MQTT": enabled
2024-07-08 22:01:00,093 - DeyeProcessorFactory - INFO - Feature "Set inverter time once online": enabled
2024-07-08 22:01:00,093 - DeyeProcessorFactory - INFO - Feature "Time-of-use configuration over MQTT": enabled
2024-07-08 22:01:00,093 - DeyeProcessorFactory - INFO - Feature "Active power regulation over MQTT": enabled
2024-07-08 22:01:00,093 - DeyePluginLoader - INFO - Loading custom event processor: 'sample_publisher'
2024-07-08 22:01:00,105 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:00,109 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:01,111 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r1, m1), 'b'deye/status'', ... (6 bytes)
2024-07-08 22:01:01,111 - DeyeMqttClient - INFO - Successfully connected to MQTT Broker located at 10.0.1.200:1883
2024-07-08 22:01:01,111 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/selling/command
2024-07-08 22:01:01,111 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m2) [(b'deye/timeofuse/selling/command', 1)]
2024-07-08 22:01:01,111 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/1/command
2024-07-08 22:01:01,111 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m3) [(b'deye/timeofuse/time/1/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/2/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m4) [(b'deye/timeofuse/time/2/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/3/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m5) [(b'deye/timeofuse/time/3/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/4/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m6) [(b'deye/timeofuse/time/4/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/5/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m7) [(b'deye/timeofuse/time/5/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/time/6/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m8) [(b'deye/timeofuse/time/6/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/1/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m9) [(b'deye/timeofuse/power/1/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/2/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m10) [(b'deye/timeofuse/power/2/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/3/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m11) [(b'deye/timeofuse/power/3/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/4/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m12) [(b'deye/timeofuse/power/4/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/5/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m13) [(b'deye/timeofuse/power/5/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/power/6/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m14) [(b'deye/timeofuse/power/6/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/1/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m15) [(b'deye/timeofuse/voltage/1/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/2/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m16) [(b'deye/timeofuse/voltage/2/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/3/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m17) [(b'deye/timeofuse/voltage/3/command', 1)]
2024-07-08 22:01:01,112 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/4/command
2024-07-08 22:01:01,112 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m18) [(b'deye/timeofuse/voltage/4/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/5/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m19) [(b'deye/timeofuse/voltage/5/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/voltage/6/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m20) [(b'deye/timeofuse/voltage/6/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/1/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m21) [(b'deye/timeofuse/soc/1/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/2/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m22) [(b'deye/timeofuse/soc/2/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/3/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m23) [(b'deye/timeofuse/soc/3/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/4/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m24) [(b'deye/timeofuse/soc/4/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/5/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m25) [(b'deye/timeofuse/soc/5/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/soc/6/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m26) [(b'deye/timeofuse/soc/6/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/1/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m27) [(b'deye/timeofuse/enabled/1/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/2/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m28) [(b'deye/timeofuse/enabled/2/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/3/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m29) [(b'deye/timeofuse/enabled/3/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/4/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m30) [(b'deye/timeofuse/enabled/4/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/5/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m31) [(b'deye/timeofuse/enabled/5/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/enabled/6/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m32) [(b'deye/timeofuse/enabled/6/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/timeofuse/control/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m33) [(b'deye/timeofuse/control/command', 1)]
2024-07-08 22:01:01,113 - DeyeMqttClient - INFO - Subscribing to topic: deye/settings/active_power_regulation/command
2024-07-08 22:01:01,113 - paho.mqtt.client - DEBUG - Sending SUBSCRIBE (d0, m34) [(b'deye/settings/active_power_regulation/command', 1)]
2024-07-08 22:01:01,113 - DeyeDaemon - DEBUG - Starting executing the runner at intervals of 60 seconds
2024-07-08 22:01:01,120 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 1)
2024-07-08 22:01:01,127 - paho.mqtt.client - DEBUG - Received SUBACK
2024-07-08 22:01:02,461 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:02,466 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:04,508 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:04,513 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:06,553 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:06,558 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:08,708 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:08,713 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:09,119 - DeyeDaemon - DEBUG - Invoking action
2024-07-08 22:01:09,119 - DeyeInverterState - INFO - Reading start
2024-07-08 22:01:09,119 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3'}, range: 0202-022e]
2024-07-08 22:01:09,119 - DeyeModbusTcp - DEBUG - modbus_frame '01030202002d25af'
2024-07-08 22:01:09,119 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a602000000000000000000000000000001030202002d25af0615'
2024-07-08 22:01:09,129 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a602000000000000000000000000000001030202002d25af0615
2024-07-08 22:01:09,743 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a56d001015008eed1ae2a60201be220c00b8190000b614806601035a0059003602f4000002ef0000001403d60072000017010000003a0336000001940000000000000000080f0000000000000000000004e205fa000000000000000000000000000000000a000001000500000000000000000000000066caae15
2024-07-08 22:01:09,744 - DeyeModbusTcp - DEBUG - resp_frame 'a56d001015008eed1ae2a60201be220c00b8190000b614806601035a0059003602f4000002ef0000001403d60072000017010000003a0336000001940000000000000000080f0000000000000000000004e205fa000000000000000000000000000000000a000001000500000000000000000000000066caae15'
2024-07-08 22:01:09,744 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3_battery'}, range: 024a-024f]
2024-07-08 22:01:09,744 - DeyeModbusTcp - DEBUG - modbus_frame '0103024a0006e5a6'
2024-07-08 22:01:09,744 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a60200000000000000000000000000000103024a0006e5a6de15'
2024-07-08 22:01:09,753 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a60200000000000000000000000000000103024a0006e5a6de15
2024-07-08 22:01:09,835 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a51f001015008fed1ae2a60201be220c00b8190000b614806601030c05001474005300000a9c144427fee515
2024-07-08 22:01:09,835 - DeyeModbusTcp - DEBUG - resp_frame 'a51f001015008fed1ae2a60201be220c00b8190000b614806601030c05001474005300000a9c144427fee515'
2024-07-08 22:01:09,835 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3'}, range: 0256-027c]
2024-07-08 22:01:09,835 - DeyeModbusTcp - DEBUG - modbus_frame '010302560027e478'
2024-07-08 22:01:09,835 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a6020000000000000000000000000000010302560027e478dc15'
2024-07-08 22:01:09,840 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a6020000000000000000000000000000010302560027e478dc15
2024-07-08 22:01:10,007 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5610010150090ed1ae2a60201bf220c00b9190000b614806601034e08da08c608f9000000000000f6eaffeaff3df611000013880403001c005800a90052006f0014000000010015000000000014000000010015000008dc08c308f6040600000046092c001b00ce0a1588aa6615
2024-07-08 22:01:10,008 - DeyeModbusTcp - DEBUG - resp_frame 'a5610010150090ed1ae2a60201bf220c00b9190000b614806601034e08da08c608f9000000000000f6eaffeaff3df611000013880403001c005800a90052006f0014000000010015000000000014000000010015000008dc08c308f6040600000046092c001b00ce0a1588aa6615'
2024-07-08 22:01:10,008 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3_ups'}, range: 0284-028d]
2024-07-08 22:01:10,008 - DeyeModbusTcp - DEBUG - modbus_frame '01030284000a845c'
2024-07-08 22:01:10,008 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a602000000000000000000000000000001030284000a845c7115'
2024-07-08 22:01:10,014 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a602000000000000000000000000000001030284000a845c7115
2024-07-08 22:01:10,118 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5270010150091ed1ae2a60201bf220c00b9190000b614806601031408d808c608ec0000000000000940001b00cf0a2ad005d415
2024-07-08 22:01:10,118 - DeyeModbusTcp - DEBUG - resp_frame 'a5270010150091ed1ae2a60201bf220c00b9190000b614806601031408d808c608ec0000000000000940001b00cf0a2ad005d415'
2024-07-08 22:01:10,118 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3'}, range: 02a0-02a7]
2024-07-08 22:01:10,118 - DeyeModbusTcp - DEBUG - modbus_frame '010302a000084596'
2024-07-08 22:01:10,118 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a6020000000000000000000000000000010302a0000845968615'
2024-07-08 22:01:10,126 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a6020000000000000000000000000000010302a0000845968615
2024-07-08 22:01:10,219 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5230010150092ed1ae2a60201bf220c00b9190000b6148066010310000000000000000011fa0000013300008f652215
2024-07-08 22:01:10,220 - DeyeModbusTcp - DEBUG - resp_frame 'a5230010150092ed1ae2a60201bf220c00b9190000b6148066010310000000000000000011fa0000013300008f652215'
2024-07-08 22:01:10,220 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3_timeofuse'}, range: 0092-00b1]
2024-07-08 22:01:10,220 - DeyeModbusTcp - DEBUG - modbus_frame '010300920020e5ff'
2024-07-08 22:01:10,220 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a6020000000000000000000000000000010300920020e5ff9715'
2024-07-08 22:01:10,236 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a6020000000000000000000000000000010300920020e5ff9715
2024-07-08 22:01:10,380 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5530010150093ed1ae2a60201bf220c00b9190000b614806601034000ff000100c803e8044c057806a408342ee02ee02ee02ee02ee02454132413241324132413241324000a000a001e003c000a000a0000000000000000000000001870c815
2024-07-08 22:01:10,380 - DeyeModbusTcp - DEBUG - resp_frame 'a5530010150093ed1ae2a60201bf220c00b9190000b614806601034000ff000100c803e8044c057806a408342ee02ee02ee02ee02ee02454132413241324132413241324000a000a001e003c000a000a0000000000000000000000001870c815'
2024-07-08 22:01:10,380 - DeyeInverterState - INFO - Reading registers [metrics group: {'deye_sg04lp3_generator'}, range: 0295-029b]
2024-07-08 22:01:10,380 - DeyeModbusTcp - DEBUG - modbus_frame '010302950007159c'
2024-07-08 22:01:10,381 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a6020000000000000000000000000000010302950007159c5015'
2024-07-08 22:01:10,385 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a6020000000000000000000000000000010302950007159c5015
2024-07-08 22:01:10,482 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5210010150094ed1ae2a60201bf220c00b9190000b614806601030e0008000100040000000000000000c6612115
2024-07-08 22:01:10,482 - DeyeModbusTcp - DEBUG - resp_frame 'a5210010150094ed1ae2a60201bf220c00b9190000b614806601030e0008000100040000000000000000c6612115'
2024-07-08 22:01:10,482 - DeyeInverterState - INFO - Reading registers [metrics group: {'settings', 'settings_micro'}, range: 0028-0028]
2024-07-08 22:01:10,482 - DeyeModbusTcp - DEBUG - modbus_frame '0103002800010402'
2024-07-08 22:01:10,482 - DeyeModbusTcp - DEBUG - req_frame 'a5170010450000ed1ae2a602000000000000000000000000000001030028000104023015'
2024-07-08 22:01:10,488 - DeyeTcpConnector - DEBUG - Request frame: a5170010450000ed1ae2a602000000000000000000000000000001030028000104023015
2024-07-08 22:01:10,573 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5150010150095ed1ae2a60201bf220c00b9190000b61480660103020000b844d215
2024-07-08 22:01:10,573 - DeyeModbusTcp - DEBUG - resp_frame 'a5150010150095ed1ae2a60201bf220c00b9190000b61480660103020000b844d215'
2024-07-08 22:01:10,573 - DeyeInverterState - DEBUG - PV1 Power: 0.0
2024-07-08 22:01:10,573 - DeyeInverterState - DEBUG - PV2 Power: 0.0
2024-07-08 22:01:10,573 - DeyeInverterState - DEBUG - PV1 Voltage: 460.2
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - PV2 Voltage: 30.7
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - PV1 Current: 0.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - PV2 Current: 0.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Daily Production: 40.4
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Total Production: 206.3
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Daily Battery Charge: 8.9
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Daily Battery Discharge: 5.4
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Total Battery Charge: 75.6
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Total Battery Discharge: 75.1
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Battery Power: 2716.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Battery Voltage: 52.4
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Battery SOC: 83.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Battery Current: 51.9
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Battery Temperature: 28.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Total Grid Power: 21.0
2024-07-08 22:01:10,574 - DeyeInverterState - DEBUG - Grid Voltage L1: 226.6
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Grid Voltage L2: 224.6
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Grid Voltage L3: 229.7
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Internal CT L1 Power: -2326.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Internal CT L2 Power: -22.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Internal CT L3 Power: -195.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - External CT L1 Power: 20.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - External CT L2 Power: 0.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - External CT L3 Power: 1.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Daily Energy Bought: 2.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Total Energy Bought: 11.4
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Daily Energy Sold: 98.2
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Total Energy Sold: 588.9
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Total Load Power: 2602.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load L1 Power: 2368.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load L2 Power: 27.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load L3 Power: 207.0
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load Voltage L1: 226.4
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load Voltage L2: 224.6
2024-07-08 22:01:10,575 - DeyeInverterState - DEBUG - Load Voltage L3: 228.4
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Daily Load Consumption: 5.8
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Total Load Consumption: 82.2
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Current L1: 10.3
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Current L2: 0.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Current L3: 0.7
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Inverter L1 Power: 2348.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Inverter L2 Power: 27.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Inverter L3 Power: 206.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - DC Temperature: 25.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - AC Temperature: 53.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Weekly Selling Schedule: 255.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 1: 200.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 2: 1000.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 3: 1100.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 4: 1400.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 5: 1700.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Time 6: 2100.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Power 1: 12000.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Power 2: 12000.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Power 3: 12000.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Power 4: 12000.0
2024-07-08 22:01:10,576 - DeyeInverterState - DEBUG - Time of Use Power 5: 12000.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Power 6: 9300.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 1: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 2: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 3: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 4: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 5: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Voltage 6: 49.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 1: 10.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 2: 10.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 3: 30.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 4: 60.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 5: 10.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use SOC 6: 10.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 1: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 2: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 3: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 4: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 5: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Time of Use Charge Enable 6: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase voltage of Gen port A: 0.8
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase voltage of Gen port B: 0.1
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase voltage of Gen port C: 0.4
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase power of Gen port A: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase power of Gen port B: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Phase power of Gen port C: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Total Power of Gen Ports: 0.0
2024-07-08 22:01:10,577 - DeyeInverterState - DEBUG - Daily Generator Production: 0.0
2024-07-08 22:01:10,578 - DeyeInverterState - DEBUG - Active power regulation: 0.0
2024-07-08 22:01:10,578 - DeyeMqttClient - DEBUG - Publishing message. topic: 'deye/logger_status', value: 'online'
2024-07-08 22:01:10,580 - DeyeMqttPublisher - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected. Traceback (most recent call last):
  File "/Repos/deye-original/src/deye_mqtt.py", line 103, in publish
    info.wait_for_publish(self.__mqtt_timeout)
  File "/Library/Caches/pypoetry/virtualenvs/deye-inverter-mqtt-vkcN7wHu-py3.12/lib/python3.12/site-packages/paho/mqtt/client.py", line 362, in wait_for_publish
    raise RuntimeError('Message publish failed: %s' % (error_string(self.rc)))
RuntimeError: Message publish failed: The client is not currently connected.

2024-07-08 22:01:10,580 - DeyeModbus - DEBUG - Extending request frame with 1807
2024-07-08 22:01:10,580 - DeyeModbus - DEBUG - Extending request frame with 0816
2024-07-08 22:01:10,580 - DeyeModbus - DEBUG - Extending request frame with 010a
2024-07-08 22:01:10,580 - DeyeModbusTcp - DEBUG - modbus_frame '0110001600030618070816010ad321'
2024-07-08 22:01:10,580 - DeyeModbusTcp - DEBUG - req_frame 'a51e0010450000ed1ae2a60200000000000000000000000000000110001600030618070816010ad3217015'
2024-07-08 22:01:10,589 - DeyeTcpConnector - DEBUG - Request frame: a51e0010450000ed1ae2a60200000000000000000000000000000110001600030618070816010ad3217015
2024-07-08 22:01:10,753 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:10,758 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:10,758 - paho.mqtt.client - DEBUG - Sending PUBLISH (d0, q1, r0, m35), 'b'deye/logger_status'', ... (6 bytes)
2024-07-08 22:01:10,762 - paho.mqtt.client - DEBUG - Received PUBACK (Mid: 35)
2024-07-08 22:01:12,609 - DeyeTcpConnector - DEBUG - Received response frame in 1. attempt: a5100010150096ed1ae2a60201c1220c00bb190000b61480660500d515
2024-07-08 22:01:12,610 - DeyeModbusTcp - DEBUG - resp_frame 'a5100010150096ed1ae2a60201c1220c00bb190000b61480660500d515'
2024-07-08 22:01:12,610 - DeyeModbusTcp - ERROR - Modbus device address does not match.
2024-07-08 22:01:12,610 - DeyeSetTimeProcessor - WARNING - Failed to set logger time
Processing events from logger: 0
{'name': 'dc/pv1/power', 'value': 0}
{'name': 'dc/pv2/power', 'value': 0}
{'name': 'dc/pv1/voltage', 'value': 460.20000000000005}
{'name': 'dc/pv2/voltage', 'value': 30.700000000000003}
{'name': 'dc/pv1/current', 'value': 0.0}
{'name': 'dc/pv2/current', 'value': 0.0}
{'name': 'day_energy', 'value': 40.400000000000006}
{'name': 'total_energy', 'value': 206.3}
{'name': 'battery/daily_charge', 'value': 8.9}
{'name': 'battery/daily_discharge', 'value': 5.4}
{'name': 'battery/total_charge', 'value': 75.60000000000001}
{'name': 'battery/total_discharge', 'value': 75.10000000000001}
{'name': 'battery/power', 'value': 2716}
{'name': 'battery/voltage', 'value': 52.36}
{'name': 'battery/soc', 'value': 83}
{'name': 'battery/current', 'value': 51.88}
{'name': 'battery/temperature', 'value': 28.0}
{'name': 'ac/total_power', 'value': 21}
{'name': 'ac/l1/voltage', 'value': 226.60000000000002}
{'name': 'ac/l2/voltage', 'value': 224.60000000000002}
{'name': 'ac/l3/voltage', 'value': 229.70000000000002}
{'name': 'ac/l1/ct/internal', 'value': -2326}
{'name': 'ac/l2/ct/internal', 'value': -22}
{'name': 'ac/l3/ct/internal', 'value': -195}
{'name': 'ac/l1/ct/external', 'value': 20}
{'name': 'ac/l2/ct/external', 'value': 0}
{'name': 'ac/l3/ct/external', 'value': 1}
{'name': 'ac/daily_energy_bought', 'value': 2.0}
{'name': 'ac/total_energy_bought', 'value': 11.4}
{'name': 'ac/daily_energy_sold', 'value': 98.2}
{'name': 'ac/total_energy_sold', 'value': 588.9}
{'name': 'ac/ups/total_power', 'value': 2602}
{'name': 'ac/ups/l1/power', 'value': 2368}
{'name': 'ac/ups/l2/power', 'value': 27}
{'name': 'ac/ups/l3/power', 'value': 207}
{'name': 'ac/ups/l1/voltage', 'value': 226.4}
{'name': 'ac/ups/l2/voltage', 'value': 224.60000000000002}
{'name': 'ac/ups/l3/voltage', 'value': 228.4}
{'name': 'ac/ups/daily_energy', 'value': 5.800000000000001}
{'name': 'ac/ups/total_energy', 'value': 82.2}
{'name': 'ac/l1/current', 'value': 10.3}
{'name': 'ac/l2/current', 'value': 0.0}
{'name': 'ac/l3/current', 'value': 0.7000000000000001}
{'name': 'ac/l1/power', 'value': 2348}
{'name': 'ac/l2/power', 'value': 27}
{'name': 'ac/l3/power', 'value': 206}
{'name': 'radiator_temp', 'value': 25.0}
{'name': 'ac/temperature', 'value': 53.0}
{'name': 'timeofuse/selling', 'value': 255}
{'name': 'timeofuse/time/1', 'value': 200}
{'name': 'timeofuse/time/2', 'value': 1000}
{'name': 'timeofuse/time/3', 'value': 1100}
{'name': 'timeofuse/time/4', 'value': 1400}
{'name': 'timeofuse/time/5', 'value': 1700}
{'name': 'timeofuse/time/6', 'value': 2100}
{'name': 'timeofuse/power/1', 'value': 12000}
{'name': 'timeofuse/power/2', 'value': 12000}
{'name': 'timeofuse/power/3', 'value': 12000}
{'name': 'timeofuse/power/4', 'value': 12000}
{'name': 'timeofuse/power/5', 'value': 12000}
{'name': 'timeofuse/power/6', 'value': 9300}
{'name': 'timeofuse/voltage/1', 'value': 49.0}
{'name': 'timeofuse/voltage/2', 'value': 49.0}
{'name': 'timeofuse/voltage/3', 'value': 49.0}
{'name': 'timeofuse/voltage/4', 'value': 49.0}
{'name': 'timeofuse/voltage/5', 'value': 49.0}
{'name': 'timeofuse/voltage/6', 'value': 49.0}
{'name': 'timeofuse/soc/1', 'value': 10}
{'name': 'timeofuse/soc/2', 'value': 10}
{'name': 'timeofuse/soc/3', 'value': 30}
{'name': 'timeofuse/soc/4', 'value': 60}
{'name': 'timeofuse/soc/5', 'value': 10}
{'name': 'timeofuse/soc/6', 'value': 10}
{'name': 'timeofuse/enabled/1', 'value': 0}
{'name': 'timeofuse/enabled/2', 'value': 0}
{'name': 'timeofuse/enabled/3', 'value': 0}
{'name': 'timeofuse/enabled/4', 'value': 0}
{'name': 'timeofuse/enabled/5', 'value': 0}
{'name': 'timeofuse/enabled/6', 'value': 0}
{'name': 'ac/generator/a/voltage', 'value': 0.8}
{'name': 'ac/generator/b/voltage', 'value': 0.1}
{'name': 'ac/generator/c/voltage', 'value': 0.4}
{'name': 'ac/generator/a/power', 'value': 0}
{'name': 'ac/generator/b/power', 'value': 0}
{'name': 'ac/generator/c/power', 'value': 0}
{'name': 'ac/generator/total_power', 'value': 0}
{'name': 'ac/generator/daily_energy', 'value': 0.0}
{'name': 'settings/active_power_regulation', 'value': 0.0}
2024-07-08 22:01:12,610 - DeyeInverterState - INFO - Reading completed
2024-07-08 22:01:12,799 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:12,804 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:14,852 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:14,857 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
2024-07-08 22:01:16,898 - paho.mqtt.client - DEBUG - Sending CONNECT (u0, p0, wr1, wq1, wf1, c1, k60) client_id=b'deye-inverter-2799835885'
2024-07-08 22:01:16,903 - paho.mqtt.client - DEBUG - Received CONNACK (0, 0)
^Z
kbialek commented 1 month ago

Can it be that you have some wifi networking issues? The erros are reported for both MQTT and Modbus, but these connections are unrelated with each other.

karolisju commented 1 month ago

Thank you for replay.

I did another test. started ping command from PC where debugging, to Inverter and to MQTT broker. Launched local-run.sh (this time haven't got DeyeMqttPublisher error)

so it makes sense why randomly getting DeyeMqttPublisher - ERROR, maybe it is possible to increase timeout or retry?

and any clue about this “DeyeModbusTcp - ERROR - Modbus device address does not match.”? (this error always repeats)

kbialek commented 1 month ago

and any clue about this “DeyeModbusTcp - ERROR - Modbus device address does not match.”? (this error always repeats)

It indicates that the Modbus response contains unexpected values. Perhaps your inverter model uses different Modbus registers for date/time data?

github-actions[bot] commented 1 week ago

This issue is stale because it has been open for 30 days with no activity.