sircuri / GoodWeUSBLogger

Python based logger for GoodWe inverters using USB.
GNU General Public License v3.0
10 stars 7 forks source link

Looping StateMachine State DISCOVERY #13

Open ferdyh opened 5 years ago

ferdyh commented 5 years ago

Any idea as to why I keep getting this message on a loop every 30 seconds or so?

2019-09-27 09:09:51,543 resetUSBDevice(191) - DEBUG: Found GoodWe Inverter at /dev/hidraw1
2019-09-27 09:09:51,602 openDevice(229) - DEBUG: Connected to /dev/hidraw1
2019-09-27 09:09:51,702 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x0 0x2 0x0 0x1 0x8c
2019-09-27 09:09:52,807 sendDiscovery(516) - DEBUG: Sending discovery
2019-09-27 09:09:52,807 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0x7f 0x0 0x0 0x0 0x1 0xfe
2019-09-27 09:10:01,730 handle(551) - DEBUG: State machine time-out. Last state: State.DISCOVER
sircuri commented 5 years ago

Is means that your inverter does not respond to the Discovery command. Does this happen the whole day? There are users that need to wait for the next day before it starts working. For them the inverter needs to be offline with the raspberry connected. When the inverter wakes up in the morning with the rasperry connected everything started to work. I don't have these issues, but it might be worth to try for you in this case.

ferdyh commented 5 years ago

Hmm, I can give it a shot. But does that mean that I can't restart the program without waiting a day?

sircuri commented 5 years ago

It appears that way. But as I said I don't have these kind of issues. What inverter type do you have?

ferdyh commented 5 years ago

3600D-NS

Worked today (next day), however half day it stopped again same message.

ferdyh commented 5 years ago

Stops everyday at around 11:30/noon...

2019-10-02 10:10:29,077 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x1 0x1 0x0 0x1 0x8c
2019-10-02 10:10:29,879 run_process(79) - DEBUG: Publishing telegram to MQTT on channel goodwe/93600DSN182W0024/data
2019-10-02 10:10:29,880 run_process(81) - DEBUG: Publishing 1 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:10:30,883 run_process(79) - DEBUG: Publishing telegram to MQTT on channel goodwe/93600DSN182W0024/data
2019-10-02 10:10:30,883 run_process(81) - DEBUG: Publishing 1 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:10:31,585 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x1 0x1 0x0 0x1 0x8c
2019-10-02 10:10:31,886 run_process(79) - DEBUG: Publishing telegram to MQTT on channel goodwe/93600DSN182W0024/data
2019-10-02 10:10:34,897 run_process(79) - DEBUG: Publishing telegram to MQTT on channel goodwe/93600DSN182W0024/data
2019-10-02 10:10:34,897 run_process(81) - DEBUG: Publishing 1 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:10:35,901 run_process(79) - DEBUG: Publishing telegram to MQTT on channel goodwe/93600DSN182W0024/data
2019-10-02 10:10:35,901 run_process(81) - DEBUG: Publishing 1 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:10:36,603 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x1 0x1 0x0 0x1 0x8c
2019-10-02 10:10:36,904 checkOfflineInverter(527) - INFO: Marking inverter @ address 11 offline
2019-10-02 10:10:36,904 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:07,041 resetUSBDevice(191) - DEBUG: Found GoodWe Inverter at /dev/hidraw1
2019-10-02 10:11:07,102 openDevice(229) - DEBUG: Connected to /dev/hidraw1
2019-10-02 10:11:07,102 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:07,203 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x0 0x2 0x0 0x1 0x8c
2019-10-02 10:11:08,204 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:08,306 sendDiscovery(516) - DEBUG: Sending discovery
2019-10-02 10:11:08,307 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0x7f 0x0 0x0 0x0 0x1 0xfe
2019-10-02 10:11:09,212 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:10,215 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:11,217 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:12,220 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:13,223 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:14,225 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:15,228 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:16,231 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:17,233 handle(551) - DEBUG: State machine time-out. Last state: State.DISCOVER
2019-10-02 10:11:47,272 resetUSBDevice(191) - DEBUG: Found GoodWe Inverter at /dev/hidraw1
2019-10-02 10:11:47,330 openDevice(229) - DEBUG: Connected to /dev/hidraw1
2019-10-02 10:11:47,330 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:47,430 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x0 0x2 0x0 0x1 0x8c
2019-10-02 10:11:48,432 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:48,534 sendDiscovery(516) - DEBUG: Sending discovery
2019-10-02 10:11:48,534 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0x7f 0x0 0x0 0x0 0x1 0xfe
2019-10-02 10:11:49,440 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:50,442 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:51,445 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:52,448 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:53,450 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:54,453 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:55,455 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:56,458 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:11:57,460 handle(551) - DEBUG: State machine time-out. Last state: State.DISCOVER
2019-10-02 10:12:27,496 resetUSBDevice(191) - DEBUG: Found GoodWe Inverter at /dev/hidraw1
2019-10-02 10:12:27,558 openDevice(229) - DEBUG: Connected to /dev/hidraw1
2019-10-02 10:12:27,558 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online
2019-10-02 10:12:27,658 sendData(282) - DEBUG: Sending data to inverter: 0xcc 0x99 0x9 0xaa 0x55 0x80 0xb 0x0 0x2 0x0 0x1 0x8c
2019-10-02 10:12:28,660 run_process(84) - DEBUG: Publishing 0 to MQTT on channel goodwe/93600DSN182W0024/online

edit: added piece of logging when stops sending out data.

sircuri commented 5 years ago

Sorry, didn't realise you updated this question with additional logging.

Can you please also post your full config file?

ferdyh commented 5 years ago
[inverter]
loglevel = DEBUG
pollinterval = 1000
vendorId = 0084
modelId = 0041
logfile = /var/log/goodwe.log

[mqtt]
server = 192.168.10.250
port = 1883
topic = goodwe
clientid = goodwe-usb
username = 
password = 
sircuri commented 5 years ago

Can you please increase the pollinterval to 5000. Might be that you request too often.

ferdyh commented 5 years ago

I've put it on 5000 poll interval, still stopped around 10:30 am.

GijsvanDulmen commented 4 years ago

@ferdyh did you ever solve it somehow?

ferdyh commented 4 years ago

@ferdyh did you ever solve it somehow?

@GijsvanDulmen nope, running it on another machine now without issues... Probably not the answer you're looking for

GijsvanDulmen commented 4 years ago

What type of machines was it not working on and which did work if I may ask? Just to rule out my local problems on my RPi GW3000-NS inverter.

ferdyh commented 4 years ago

It didn't work on a z67 board. Got it working in a NUC with j5005. Haven't tried a rpi.

jgaalen commented 4 years ago

Having the same issue now. Connected Goodwe 5000DT (3 phase) with usb to raspberry pi 4 and discovery is timing out. Restarted the inverter but no luck. I'll keep the discovery going on until tomorrow, hopefully magically it will discover it when the sun comes up.

GijsvanDulmen commented 4 years ago

I had a RPi 3b+ for this, but recently switched to a Intel Nuc as well. No problems since then running it on kubernetes. More info over here in this fork: https://github.com/sircuri/GoodWeUSBLogger/compare/master...GijsvanDulmen:master