patience4711 / read-APSystems-YC600-QS1-DS3

Software for an esp8266 nodemcu to read data from APS inverters.
130 stars 24 forks source link

No data after power down and power up #28

Closed PLCHome closed 2 years ago

PLCHome commented 2 years ago

firmware version : ESP-ECU_v9_2 time retrieved today : yes the signalstrength of the connection to the router = -22

No reconnect to Inverter after power down and power up.

I always must pair to get values.....

patience4711 commented 2 years ago

@PLCHome This is a strange problem, so far you seem to be the only one so you must be doing something different.

It would be helpfull if you tell us exactly what hardware (firmware version) you have and what you mean by a power down. Remove the powerplug from the esp? Or the inverter or both? Did you try closer to the inverter?

The only thing that i can imagine is that the Esp is losing its memory. In the infopage you should see the paired inverters, are there any? Check also the value 'invertercount'in the variablesdump You can test as follows:

If all seems to be correct you can check if the polling command contains your inverters id (reversed). In the console type 10;diag and 10;poll=0. zb send poll cmd inverter 0 cmd:1D2401BBAA1414060001000F1380971B01A3D6FBFB06BB000000000000C1FEFE3

If values are not remembered, the filesystem of the esp is damaged. You should re-install the software with wiping the whole flash. Good luck.

homeautomation2022 commented 2 years ago

I'll also get back to you because I've been able to connect to my inverter (I forgot to press pair after setting up the serial and I was a little too far away from the inverter). However, I noticed the same problem in my tests. If I unplug the ESP, it only finds the inverter again after manual pairing, until then there is no data. Maybe it will work automatically the next morning, I haven't tested that. But there is still some routine missing when booting after the power failure so that communication with the inverter works again. The ESP remembers the inverter ID in the flash, but something is done differently with the soft reboot, the consumption data of the day will hardly be, maybe an auto pairing, no idea...(I haven't looked at that in the code yet.) But it is an ugly problem, which is certainly quite easy to fix, a pairing after the boot would be enough, but I don't think that's even necessary, there may be another way to solve it and preferably without write something in the flash every 5 minutes to save because of the lifetime?

patience4711 commented 2 years ago

@PLCHome Still don't know what hardware you use. Could it have something to do with the firmware on your zigbee module? Is your polling command correct after a reboot? Still the question remains, why do you have this problem and other users not?

homeautomation2022 commented 2 years ago

As I have already written, the problem seems to affect everyone and can be simulated by briefly disconnecting the power from the ESP + Zigbee module and then reconnecting it, then you have to manually press pair to get data again. A soft reboot via the webif works. Tested with the latest version and the old YC600 CC2530 firmware.

patience4711 commented 2 years ago

Wel it could be that you think it affects everyone but i know that's not true, i cannot reproduce it myself. And i know that once paired, it is not necessary to do it again after a power cycle, or a reset of the zigbee module. Not the ESP, nor the Raspberry implementation shows this behaviour.
So i really can't help you with the information you gave me, sory. I think however that the program has so many debug capabilities that you should be able to analyze what is happening after a short power failure.

homeautomation2022 commented 2 years ago

Ok, I didn't know that, I flashed your finished binary on an ESP-12F as normal and also flashed the CC2530 firmware from the zip with CCLoader for ESP8266. Then I entered the serial, hooked the panel and pressed pair, that's all it takes. and with this constellation, the ESP does not connect automatically after the plug is pulled, but you are probably right, if it is not the case with you, I and PLCHome will have to investigate the reason for this ourselves. I still have to build a driver from your code and then integrate it into my electricity meter project. But I need time for that...

patience4711 commented 2 years ago

If you have an ESP-12F your zigbee module is probably not powered by the ESP as would be the case if you use a NodeMCU. Maybe that is the cause. You should have told me that, i asked several times what your hardware is.

Disconnecting the power: there is a difference between pulling the powerplug out of the wallsocket and disconnect the power to the esp. When pulling the plug, the power unit discharges slowly what could lead to a brown-out of the zigbeemodule, (cc2530 or cc2531?) i don't know. And when you do this briefly some unexpected things may happen.

Anyway, when after a powercycle the health of the zigbee coordinator is oke, it should poll correctly.

homeautomation2022 commented 2 years ago

The 3.3V are connected directly to each other, I'm currently testing with a Wemos D1 Mini and USB power supply, so very similar to your setup in the picture, same problem. I will try it again directly by pulling the USB cable without capacity. But the problem would still exist after a power failure. As already written Zigbee module is a CC2530. EDIT: I have now tested it directly via the USB cable, the problem persists as expected. I set the diagnostics to 1 after the start, then the following appears after short time: zb send poll cmd inverter 0 cmd:1D2401XXXX1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE1F polling answer FE0164010266 AF_DATA_REQUEST failed polling failed 10 ------ and few seconds later (I think at % 5 min) ------- zb send poll cmd inverter 0 cmd:1D2401XXXX1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE1F polling answer FE0164010266 AF_DATA_REQUEST failed polling failed 10 inMessage = FE02610179071C rc = 7 ping ok inMessage = FE0E670000FFFF80971B01A3D8000007090011 rc = 19 found 0709 ------ and then again send poll ... -----

patience4711 commented 2 years ago

@PLCHome So in short, after a powercycle of your hardware, the polling process does'nt work anymore. After pairing it works again.
The pollcommand 1D2401XXXX1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE1F is not valid so you never will get an answer to this. The are a few things to notice: The inverter does not get unpaired (this is not possible), it just doesn't answer to the poll command anymore. The software considers the inverter to be paired as long as there is a short id (like 0x12AB) and sends this in the pollcommand.

You suggest that a solution would be some autopairing at boot. I really don't like that, it would imply a very complicated operation which would cause the whole boot process to take very long. There is no way to check if an inverter is paired or should be re-paired. This means that if you would have 9 inverters we would have to pair them all, every boot. And what to do if the pairing fails? So i am not considering putting that in.

But i am still wondering why you have that. What happens if you power cycle only the esp or only the cc2530? What happens if you change the ECU-id into D6A3011B9780 ? What happens if you do this closer to the inverter. (how far away are you)? You could check the wiring to your cc2530, a bad solder joint? What happens if you only reboot the ESP (resetbutton or reboot in the webpage)?

homeautomation2022 commented 2 years ago

As I have already written, a restart in the webif works and otherwise data comes day after day without any problems, only if I unplug the ESP + CC2530 Power connected to it, then only the failed poll cmd´s comes in the log. Maybe you could only trigger a new pairing if the error occurs after the restart. The inverter is on all the time during the restart! I'm only 5m away from the inverter and as I said, once paired, data comes for days without dropouts, so I rule out a reception problem and a faulty solder joint. I use the standard ECU ID and have no problems with it once paired. I made the XXXX in the log to make my ID unrecognizable, but the CMD otherwise correct? The ID of the inverter is available and saved, never changes even when paired again. So you mean your program sends the poll correctly, but the inverter no longer responds, although nothing has changed there. When you restart the software, do you save anything in the EEPROM that is missing with the power reset? RAM is completely cleared. Nothing can get lost in the CC3530, which is reset when booting anyway.

And by the way, you have easily compilable code for Arduino IDE with libraries, preferably in zip format, so anyone can unzip and build it. When I clone the git and post-install the libraries, I get error after error and lots of warnings.

EDIT: It also seems to work via the reset button of the ESP (CC2530 remains powered), but after pulling the plug it doesn't. Does the Zigbee module have to be reset (+ possibly initialized) when the ESP is restarted, which is currently missing?

patience4711 commented 2 years ago

@PLCHome Eeprom cannot have anything to do with it. And when ESP boots, it always checks the coordinators health and initializes it when needed. You can see that for yourself bij typing 10;health. So basicly the difference here is that the ZB coordinator keeps running when the esp is reset, and not when powered down.
For the ESP it makes no difference, a reboot (reset) or powercycle. So in fact, the real problem is that when you powercylce the cc2530, the inverter does not respond anymore.

When the ESP boots it always checks the coordinators health and initializes it when needed. You can see that for yourself bij typing 10;health. So in the end, after a reboot or powercycle we have exactly the same state as before.

So why, in your case, the zb communication needs to be recovered. And why is this accomplished by re-pairing, it does not make any sense. Maybe a reset of the inverter (the next morning) could also restore the communication but you didn't test that?

If you don't think that the tests i suggested could yield something usefull i am out of options. You can rule out the reception problems if you tested this nearby the inverter. A faulty solder joint in the reset wire can have impact on the starting of the coordinator. Again, it must have something to do with your local circumstances, otherwise everybody would have this problem.

As said, there is no way to check if re-pairing is needed, even when polling fails (which incidently happens from time to time) this can have other causes and cannot be used as a trigger to re-pair.

As for your other problem, i cannot solve that. I made the software available so that everyone can put in their own features or housestyle but I do not support that further, gives me too much work. There are closed issues on this subject where you can read.

homeautomation2022 commented 2 years ago

OK, I agree with you, it doesn't seem to be directly related to the program, because no matter which way you restart the ESP, it is completely reset internally. As you have correctly identified, the problem lies with the power reset of the CC2530. I can't log what exactly the ESP is doing when booting because the web console isn't working at the time and unfortunately I can't upload my own program. But I can say that the health check looks exactly the same, regardless of whether the Zigbee module can poll the inverter after the restart or not. The health check also runs at night, so it says absolutely nothing about the inverter connection status, only that the Zigbee module is probably initialized on the ECU and is running. But why is the inverter no longer responding to the polling after restarting the Zigbee module? The inverter should not notice the restart at all, since there is no ping among each other, only the "ECU" requests the data.

I pulled the plug in the middle of the night (so that it doesn't work) and will see if there is data tomorrow morning. If so, then when I wake up, something else is done differently than if I draw power from the ESP+Zigbee during the day, where the inverter stays on the whole time.

In some positions I also noticed reception problems when polling/parinring, would a CC2530+CC2591 make a noticeable difference here? My inverter is on the outside of a concrete wall and I have at least one wall in between. But what surprises me about the problem is that it works after a repair without touching anything. 10m away 3 floors higher depends on how I position the antenna, since it is unreliable. To rule out this error, I got as close to the inverter as possible, but I will always have a concrete wall and probably some steel in between.

About the program: You also have to build your binaries somehow and you also update the files here, as I can see from the changelog, but I think your status is different, because the files here are impossible to compile in this form. Could I get your Arduino project folder as a zip file + maybe the libraries, so that there are no version complications?

patience4711 commented 2 years ago

@PLCHome your summary is correct. I can't advice you about other hardware, all i have is the cc2530 and in my case about 5 meters from the inverter with only some glass between. When i walk through during polling i sometimes see disturbances so this hardware is not very reliable.

Another thing i an curious about: When you power cycle and after that the polling fails, and than you reset the ESP, would that help?

I compile with arduino IDE 1.8.13 and ESP8266 boards version 2.7.1 My project folder contains only the files you see here in this repo and the libraries are all available on the internet. For more support on compiling please see my former post.

homeautomation2022 commented 2 years ago

This morning, as almost expected, there was no data after pulling the plug during the night. A restart/reset of the ESP, whatever does not fix the error, only reinitializing/resetting the CC2530 during pairing helps. OK then it seems to be a common problem that the normal CC2530 is prone to failure. +CC2591 should help and + 2592 is not available as such a simple module with antenna and pins, only for soldering. But if the polling works at the same place after the pairing, it can't really be because of that, the reception remains the same. I think the CC2530 needs a reset + reinit as an ECU receiver when booting? to avoid the problem or is it already done this way, because the Zigbee module reports everything correctly when it comes to health, but it probably sends something wrong, which is why the inverter does not answer poll. The ESP doesn't know whether the voltage of the CC2530 was gone, but a reset every time shouldn't be a problem?

I have no idea how to get the program compiled. As I said, I tested exactly your version of the IDE and libraries, it doesn't make any difference.

patience4711 commented 2 years ago

To know that, you can do the following:

homeautomation2022 commented 2 years ago

I tested this today(after reset pulled to low):

check zb system inMessage = FE02610179071C rc = 7 ping ok inMessage = FE0E670000FFFF80971B01A3D8FEFF07000019 rc = 19 inMessage = FE00660066FE0145C0098D rc = 11 zb start success zb send poll cmd inverter 0 cmd:1D2401xxxx1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE1F polling answer FE0164010266 AF_DATA_REQUEST failed polling failed 10

Unfortunately that doesn't work, I suspect that the same thing is done when you restart, since the module was reset after you pulled the plug. The Poll CMD is always identical. Something seems to be different with the zigbee module after pairing than after a reset. I'm just surprised that the inverter doesn't respond even though the Poll CMD is exactly the same, or is that somehow still being processed in the ZB, such as adding a timestamp?

I also tried to leave everything on the electricity (worked beforehand) and only reset the module briefly and made the health, then also "zb start success", but the polling afterwards is broken again. So whenever my Zigbee module is reset, I have to trigger a pairing to get Poll again.

pixeldoc2000 commented 2 years ago

Had a similar Problem more than once, also getting no data from my Inverter after Power Cycling the inverter at nighttime because of maintenance.

Had to "repair" the Inverter during the next day via the ESP Webinterface. So it looks like the ECU does not reconnect to inverter properly. Sadly, I did not get a console output from the ESP before "repair" the inverter.

Maybe I can test it again today by disconnecting the inverter by Power Cycling to test if the ECU will reconnect to the inverter this time (my guess it does not).

Inverter: DS3-S ESP: Wemos D1 + CC2530 (both on current FW 9.3).

ECU LOG:

2-13:21:0 | mqtt | connected
-- | -- | --
12-13:15:59 | pairing | success, inverter got id 0xCDD7
12-13:15:42 | zigbee | zigbee module reset
12-13:15:42 | pairing | start pairing inverter sn xxxxxxxxxxxx
12-7:51:0     | mqtt | connected
12-5:41:4     | system | wake-up from nightmode
12-4:0:59     | mqtt | connected
12-3:0:0       | system | time retrieved
12-0:0:1       | system | all values reset
11-21:9:32   | system | start nightmode
11-11:31:2   | zigbee | Stopped reason: Tostart
11-11:11:7   | zigbee | coordinator up
11-11:11:6   | system | time retrieved
1-0:0:6         | zigbee | initial healthcheck
1-0:0:3         | mqtt | connected
1-0:0:3         | system | boot up

Console Output:

poll inverter 0
zb send poll cmd inverter 0 cmd:1D2401D7CD1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE33
polling answer FE0164010064FE034480001401D2FE0345C4D7CD0098FE0345C4D7CD0098FE7D448100000601D7CD1414004400F6BD79000069xxxxxxxxxxxxFBFB5CBBBB200003000FFFFF000000000000800007F6019D00A400010369138D5E61004C001EFFFF0509099F028284EF00005E9CFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF3971FEFED7CD7037
decoding a DS3 inverter
extracted ACV = 229.7
extracted FREQ = 50.0
extracted HEATH = 24.9
* * * * polled inverter 0 * * * *
extracted time = 24161 the timespan = 17
* * * decoding panel 0 * * *
en_incr 0.79 power 324.60
no panel 1
no panel 2
no panel 3
patience4711 commented 2 years ago

So we can safely assume that it is the CC2530. It must be something in the firmware. But why does not everybody have this?

In my raspberry project (recommended) the initialization and pairing works exactly the same as in the ESP. No problems what so ever when power-cycled. The guy who made the ZB firmware says he does not recognize this problem either. He says that the only way to find out is sniffing the zigbee trafic.

What happens with a reboot: The coodinator keeps running, which is checked at the boot process.
With a powercycle, the coordinator stops running, is checked at boot and re-initialized.

He uses other software however, so there may be a difference in how the zigbee is initialized. My software uses a hard reset and he, if i remember well, uses 4 software resets behind each other (because they are unreliable). The manufacturer recommands hard reset. So there could be a difference but that can't explain it because everyone who uses this software should have the problem then. But i think it's true that a hard reset brings the the ZB in the same state as when re-powered.

Or maybe, after pairing, the coordinator is in a different state than when normally initialized. To know that, i have to see a console log of the end of a pairing process.

Anyway, i made a test version with which we can restart the coordinator. Please change the ECU-ID to D6A3011B9780

When typing in the console, 10;INIT_N the coordinator is restarted, complete with a hard reset. So this brings it in the same state as when power-cycled. On a working system we can re-init the coordinator, to see if this causes any failure in the polling. On a not working system we can see if a re-init this recovers it.

Maybe the zigbee boots slower than the esp after powercycle. In that case it could be that a re-initialization after a longer period makes a difference. So conduct some experiments with this version, hopefully it helps.

In the past there were lots of troubles with the zigbee unit, it crashed when polling at a high rate. When re-initted it worked again, the polling also.

https://1drv.ms/u/s!AkMG5FvUwhediz6e21J8iEvNHA-R?e=usgjOV

pixeldoc2000 commented 2 years ago

firmware version : ESP-ECU_v9_3

-> Night Time (interter not responding)

Console:

poll inverter 0
zb send poll cmd inverter 0 cmd:1D2401D7CD1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE33
polling answer FE0164010064FE034480E914013B
no AF_DATA_CONFIRM
polling failed 11

flahed firmware version : ESP-ECU_v9_3_BETA

Console: -> COMMAND: 10;INIT_N

init zb coordinator
zigbee module reset
zb send cmd 0
inMessage = FE0166050062 rc = 6
zb send cmd 1
inMessage = FE064180020202020702C2 rc = 11
zb send cmd 2
inMessage = FE0166050062 rc = 6
zb send cmd 3
inMessage = FE0166050062 rc = 6
zb send cmd 4
inMessage = FE0166050062 rc = 6
zb send cmd 5
inMessage = FE0166050062 rc = 6
zb send cmd 6
inMessage = FE0164000065 rc = 6
zb send cmd 7
inMessage = FE00660066FE0145C0088CFE0145C0088CFE0145C0088C rc = 23
sending NO cmd
inMessage = FE016401C2A6FE0145C0088CFE0145C0088CFE0145C0088C rc = 24
inMessage = FE0E670000FFFF80971B01A3D8000007080010FE0145C0088CFE0145C0088C rc = 31
starting ZB coordinator failed

Log:

Time    Type    Command
12-22:57:7  zigbee  starting ZB coordinator failed
12-22:56:55 zigbee  zigbee module reset
12-22:56:18 system  start nightmode
12-22:56:17 zigbee  coordinator up
12-22:56:16 zigbee  initial healthcheck
12-22:56:13 mqtt    connected
12-22:56:13 system  boot up
12-22:56:13 system  time retrieved

PAIRING INVERTER 0 -> pairing not possible because of nighttime (interter not responding) Log:

Time    Type    Command
12-23:0:56  pair    failed, inverter got id 0x0000
12-23:0:40  zigbee  zigbee module reset
12-23:0:39  pairing start pairing inverter sn 7020000xxxxx
12-23:0:24  pair    failed, inverter got id 0x0000
12-23:0:8   zigbee  zigbee module reset
12-23:0:7   pairing start pairing inverter sn 7020000xxxxx
12-22:57:7  zigbee  starting ZB coordinator failed
12-22:56:55 zigbee  zigbee module reset
12-22:56:18 system  start nightmode
12-22:56:17 zigbee  coordinator up
12-22:56:16 zigbee  initial healthcheck
12-22:56:13 mqtt    connected

Console:

poll inverter 0
zb send poll cmd inverter 0 cmd:1D240100001414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE29
polling answer FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
no route receipt
ignoring, received FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
polling failed 15

...

poll inverter 0
zb send poll cmd inverter 0  cmd:1D240100001414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE29
polling  answer  FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
no route receipt
ignoring,  received  FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
polling failed 15
inMessage = FE02610179071C rc = 7
ping ok
inMessage = FE0E670000FFFF80971B01A3D8000007090011 rc = 19
found 0709
poll inverter 0
zb send poll cmd inverter 0  cmd:1D240100001414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE29
polling  answer  FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
no route receipt
ignoring,  received  FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
polling failed 15

Hope this helps somehow.

I will try to reconnect tomorrow morning when the inverter is available again.

pixeldoc2000 commented 2 years ago

Test after Nightmode without any changes:

Log:

Time    Type    Command
13-5:39:31  system  wake-up from nightmode
13-3:0:0    system  time retrieved
12-23:5:56  mqtt    connected
12-23:0:56  pair    failed, inverter got id 0x0000
12-23:0:40  zigbee  zigbee module reset
12-23:0:39  pairing start pairing inverter sn 7020000xxxxx
12-23:0:24  pair    failed, inverter got id 0x0000
12-23:0:8   zigbee  zigbee module reset
12-23:0:7   pairing start pairing inverter sn 7020000xxxxx
12-22:57:7  zigbee  starting ZB coordinator failed
12-22:56:55 zigbee  zigbee module reset
12-22:56:18 system  start nightmode
12-22:56:17 zigbee  coordinator up
12-22:56:16 zigbee  initial healthcheck
12-22:56:13 mqtt    connected
12-22:56:13 system  boot up
12-22:56:13 system  time retrieved

Console:

poll inverter 0
zb send poll cmd inverter 0 cmd:1D240100001414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE29
polling answer FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
no route receipt
ignoring, received FE0164010064FE034480001401D2FE274481000006000000141400FF0000000000001380971B01A3D8FBFB06BB000000000000C1FEFE00000002
polling failed 15

-> Console Command: 10;INIT_N

init zb coordinator
zigbee module reset
zb send cmd 0
inMessage = FE0166050062 rc = 6
zb send cmd 1
inMessage = FE064180020202020702C2 rc = 11
zb send cmd 2
inMessage = FE0166050062 rc = 6
zb send cmd 3
inMessage = FE0166050062 rc = 6
zb send cmd 4
inMessage = FE0166050062 rc = 6
zb send cmd 5
inMessage = FE0166050062 rc = 6
zb send cmd 6
inMessage = FE0164000065 rc = 6
zb send cmd 7
inMessage = FE00660066FE0145C0088CFE0145C0088CFE0145C0088C rc = 23
sending NO cmd
inMessage = FE016401C2A6FE0145C0088CFE0145C0088CFE0145C0088C rc = 24
inMessage = FE0E670000FFFF80971B01A3D8000007080010FE0145C0088CFE0145C0088C rc = 31
starting ZB coordinator failed

-> Inverter 0 repaired

Log:

Time    Type    Command
13-8:17:52  pairing success, inverter got id 0xCDD7
13-8:17:35  zigbee  zigbee module reset
13-8:17:35  pairing start pairing inverter sn 7020000xxxxx
13-8:16:55  zigbee  starting ZB coordinator failed
13-8:16:44  zigbee  zigbee module reset
13-5:39:31  system  wake-up from nightmode
13-3:0:0    system  time retrieved
12-23:5:56  mqtt    connected
12-23:0:56  pair    failed, inverter got id 0x0000
12-23:0:40  zigbee  zigbee module reset
12-23:0:39  pairing start pairing inverter sn 7020000xxxxx
12-23:0:24  pair    failed, inverter got id 0x0000
12-23:0:8   zigbee  zigbee module reset
12-23:0:7   pairing start pairing inverter sn 7020000xxxxx
12-22:57:7  zigbee  starting ZB coordinator failed
12-22:56:55 zigbee  zigbee module reset
12-22:56:18 system  start nightmode
12-22:56:17 zigbee  coordinator up
12-22:56:16 zigbee  initial healthcheck
12-22:56:13 mqtt    connected
  1. Poll via Console:

    poll inverter 0
    zb send poll cmd inverter 0 cmd:1D2401D7CD1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE33
    polling answer FE0164010064FE034480001401D2FE0345C4D7CD0098FE0345C4D7CD0098FE7D448100000601D7CD1414004E004501030000697020000xxxxxFBFB5CBBBB200003000FFFFF000000000000A0000869081F002C00230369138613D50020001DFFFF050D08B50018C09300141369FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF3750FEFED7CD0038
    decoding a DS3 inverter
    extracted ACV = 229.7
    extracted FREQ = 50.0
    extracted HEATH = 20.3
    * * * * polled inverter 0 * * * *
    extracted time = 5077 the timespan = 5077
    * * * decoding panel 0 * * *
    1st poll after inverter (re)start
    en_incr 30.01 power 21.28
    * * * decoding panel 1 * * *
    1st poll after inverter (re)start
    en_incr 24.34 power 17.26
    no panel 2
    no panel 3
  2. Poll via Console:

    1st poll after inverter (re)start
    en_incr 30.01 power 21.28
    * * * decoding panel 1 * * *
    1st poll after inverter (re)start
    en_incr 24.34 power 17.26
    no panel 2
    no panel 3
    poll inverter 0
    zb send poll cmd inverter 0 cmd:1D2401D7CD1414060001000F1380971B01A3D8FBFB06BB000000000000C1FEFE33
    polling answer FE0164010064FE034480001401D2FE0345C4D7CD0098FE0345C4D7CD0098FE7D448100000601D7CD1414004100618C040000697020000xxxxxFBFB5CBBBB200003000FFFFF0000000000000000084D0849002F0024036A138613F60020001EFFFF050808B70018F0B1001438D8FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF37C4FEFED7CD7007
    decoding a DS3 inverter
    extracted ACV = 230.0
    extracted FREQ = 50.0
    extracted HEATH = 20.3
    * * * * polled inverter 0 * * * *
    extracted time = 5110 the timespan = 33
    * * * decoding panel 0 * * *
    en_incr 0.23 power 24.86
    * * * decoding panel 1 * * *
    en_incr 0.18 power 19.34
    no panel 2
    no panel 3
patience4711 commented 2 years ago

@pixeldoc2000 I already knew that the polling does not work at night. Useless to post a log of that.

I notice that when you use 10;init_n you get zigbee not started When i repower my esp/zb and type 10;health, the health is oke. after 10;init_n i get :

inMessage = FE00660066FE0145C0088CFE0145C0088CFE0145C0088C rc = 23 sending NO cmd inMessage = FE016401C2A6FE0145C0098D rc = 12 inMessage = FE0E670000FFFF80971B01A3D600000709001F rc = 19 found 0709 ZB coordinator started

This means that within the evaluation time, your ZB was not started, sometimes this is a slow process. When you type 10;health after the init command, you will see that it is running.

What firmware do you have on the ZB, maybe flash the newest ds3 version. Did you change the ECU-id?

I also saw that the pairing process sometimes failes. This is why we cannot automate that. If an inverter is paired we can only know that because it has a short id, the 0x12AB.

Pairing failure is something i have never seen with my raspberry version. Software-wise there are no differences between the esp and raspberry, exactly the same commands are send to the zigbee module. Nevertheless the raspberry implementation works better and is rock stable.

So the difference must be hardware related. Maybe the radio's of the ZB and the ESP disturb, I really don't know. Since not everybody has this problem, maybe it is somthing like that. Or other local circumstances.

So i am afraid that i cannot solve this problem. Sorry

pixeldoc2000 commented 2 years ago

What firmware do you have on the ZB, maybe flash the newest ds3 version. Did you change the ECU-id?

ECU-ESP 9.3 CC2530ZNP-with-SBL.hex

Yes, I have changed ECU-id.

homeautomation2022 commented 2 years ago

I will test 10;INIT_N tomorrow. Yes, according to my tests, I also believe that a hard reset does the same thing as a power cycle. As you can see in my last log, health cannot start the coordinator properly. With your test init command, however, a lot more seems to happen, similar to pairing, since everything always works for me. So I have hope that this will work.

@pixeldoc2000 At night, the inverter is off and receives no voltage (control board), which means that neither polling nor pairing works.

@patience4711 What does the changed ECU ID do? Doesn't that matter, the main thing is that the inverter is paired with it or have you linked any special functions to it?

patience4711 commented 2 years ago

@PLCHome The program has only one sequence of commands to start the coordinator, these are issued when init_n is issued and when the healthcheck says that the zb is not running. What the changed ECU-id does? I don't know, maybe you have a neighbour with a zigbee. Maybe your inverter doesn't like the id, who knows In your last log i see that the coordinator starts properly with 10;health, only polling fails.

frtz13 commented 2 years ago

thanks for this nice piece of software. I had a problem with inverter polling after power cycling the ECU this morning, too. hardware: D1 mini pro + CC2530 ESP-ECU-v9_3. two paired YC600 inverters. after power cycle, no more success in polling: errorcode 10: AF_DATA_REQUEST failed rebooting the ECU (from the menu) did not help. did some polling attempts via the console: 10;poll=0. always got errorcode 10 then, after some time, the errorcode switched to 50 (nothing received) in response to poll requests. Then I issued the 10;health command. the ECU issued the commands to start the ZB coordinator. then polling started working.

homeautomation2022 commented 2 years ago

Unfortunately, the test version is no longer available, so I can't test the init, I was hoping that this might work. :-/

pixeldoc2000 commented 2 years ago

@homeautomation2022 Yes, I know the Inverter does not respond at night without input Voltage from the Solar Panels ;-)

@patience4711 ATM I have to repair my Inverter every Day to get Data, that's kind of inconvenient to remember...

Log: Time Type Command
15-21:15:36 system start nightmode
15-14:31:27 mqtt connected
15-14:31:25 pairing success, inverter got id 0xCDD7
15-14:31:9 zigbee zigbee module reset
15-14:31:9 pairing start pairing inverter sn 7020000xxxxx <---- manual pairing
15-5:36:31 system wake-up from nightmode
15-3:0:1 system time retrieved
15-0:0:1 system all values reset
14-21:14:6 system start nightmode
14-21:11:23 zigbee Stopped reason: Tostart
14-21:1:23 mqtt connected
14-20:52:5 zigbee starting ZB coordinator failed
14-20:51:38 zigbee zigbee module reset
14-20:51:38 zigbee zb down, received :
14-20:51:30 zigbee initial healthcheck
14-20:51:27 mqtt connected
14-20:51:27 system boot up
14-20:51:27 system time retrieved

Does the ECU Firmware reset Zigbee module after Night Mode? Does not look like it.

Maybe ECU should reset the zigbee module after Night Mode to avoid "any" possible problems?

Maybe longer wait time between zigbee module reset commands send from the ECU to the Zigbee Module could also help make it more "reliable" with different zigbee modules / power conditions / what ever maybe the problem?

pixeldoc2000 commented 2 years ago

Today didn't have to repair my inverter, strange...

patience4711 commented 2 years ago

@pixeldoc2000 No reset after night mode, just a healthcheck/re-init-if-needed.

That you didn't have to pair is not strange, that's normal. As far as i can tell you are the only one who has to re-pair after nightmode. And that is strange, because the only thing about nightmode is that there is no polling.

The testversion can tell if a re-init could help. It already has an extended delay after the hard reset. @homeautomation2022 https://1drv.ms/u/s!AkMG5FvUwhediz9mkWZeSLpUUuAo?e=iAn0eb

patience4711 commented 2 years ago

@frtz13 So the healthcheck restored the working of the system after a powercycle. The healthcheck is done after every 10 minutes so maybe it is a question of patience. It proves however that in your case no re-pairing was needed. I think your zigbee crashed due to too much polling commands, its software is sensitive to that, This explaines the no answer. And therefore it was re-initialized at healthcheck. With the testversion we can force a re-initialization, so we can test various situations,

karlheinz2000 commented 2 years ago

I did several power cycles today. Polling did never start automatically. I did always wait 30..60min before init_n. SW: ESP-ECU_v9_3_BETA. HW: CC2530 & NodeMCU ESP12

Anything else I can measure/report?

patience4711 commented 2 years ago

@karlheinz2000 Thanks for helping. To get a clear picture of the situation: Is your zigbee connected to the esp with it's vcc and gnd? And did you powercyle by pulling the usb or the wall plug of your supply? Just to rule out that the capacity of the supply can play a role.

So you say that when you 10;init_n after some period of time, the polling starts again?

If thats true than, even when the healthcheck says that the coodinator is running, a forced re-initialization restores the polling process.

If we can find the minimum of that period. I guess we can automate that.

karlheinz2000 commented 2 years ago

Zigbee module power is connected to node MCU. Node MCU is powered from USB wall wart. I disconnect wall wart from mains. Wait a few mins and connect to mains again. Then wait for >30min. No connection to inverter during this >30min.

After >30 min -> Send 10;health and waiting some minutes: 2022-05-17_10h26_11

Then 10;init_n 2022-05-17_10h30_28

Console windows scrolls. I cannot have all lines in one screen shot.

patience4711 commented 2 years ago

@karlheinz2000 Thanks, most helpfull. Are you sure that waiting a few minutes would be enough to discharge the capacity in your power? Because of the state your zigbee is in after repower, see below,

So what happens here:

Maybe this is the heart of the matter: In your log i see something totally unexpected after repower. It says that the coordinator is in some other state (to start), from which it can be started with only one startcommand. So this is what happens next in the initial healthcheck, Only the startcommand is send (2600) and not an init_n. When the coordinator's health is checked it says oke, but it has been started in a different way. That could be the cullprit.

Oke, to diagnose that, one more testversion. This one does not start the coodinator/polling/healthcheck at boot. So we have to start the coordinator manually. https://1drv.ms/u/s!AkMG5FvUwhedi0B_neSkWup_RGH6?e=pTdlGv What i would like to have tested is:

If the healthcheck does not recover the polling, you can check the log if the "reason: to start" is mentioned.

That would prove that an init_n is always needed to restore the polling process, even if the coordinator exists but needs to be started. I cannot explain this behaviour and why it is not consistent. Anyway, when that would be the case i think i can solve this problem fairly simple.

@frtz13 @homeautomation2022 @pixeldoc2000 would be nice to know if your testresults are consistent with this.

karlheinz2000 commented 2 years ago

I did tests with new SW as requested.

  • Does, after boot, an immidiate (say after 10 seconds) init_n recover the polling.

Yes. 2022-05-17_13h16_52

  • Does after boot, when we would not touch anything, the first healthcheck (after 10 minutes) recover the polling process.

No. 2022-05-17_13h37_41

Finally, after more than 45 min waiting for test#2, I sent init_n and it started polling.

patience4711 commented 2 years ago

@karlheinz2000 Good work, like i expected. I anticipated already on this result so here version esp-ecu-v9_4 that should solve it. I also changed the dc current according to your suggestion. And the conversion factor default 1,66. https://1drv.ms/u/s!AkMG5FvUwhedi0WqhyYmCXmhjtAh?e=1U2Dih

Btw, this version has still the init_n command.

karlheinz2000 commented 2 years ago

Perfect! That latest version starts polling immediately after power cycle.

homeautomation2022 commented 2 years ago

Thanks for releasing the BETA again. Yesterday I had no more sun, so I tested the init_n now and was able to find out that it works as hoped: I restart the ESP via power -> polling failed I do the command init_n -> next poll works successfully again

Now I've seen the v9.4 and I'm going to load it right away. -> v9.4 with init_n at start works for me

patience4711 commented 2 years ago

To sum it up: The re-power of a zigbee module can bring it in a state such that the coordinator can be started with a single 2600 command.

When the starting is done with a 2600 command, the polling does not work. This behaviour seems not to be consequent because not every system has it. This could have something to do with the z-stack version of the module.
In older versions the network configuration is not cleared at power up.

When during the boot process a complete sequence of initialization commands is issued, the polling is working.

In both cases however the response on a health check zb command 2700 is the same.

The new softwareversion has a healthcheck that does not distinguish the "should be started with 2600" state anymore and always issues the complete initialization sequence when the coordinator is not running.

Now we found the cause and found a solution, this issue can be closed.

PLCHome commented 2 years ago

@homeautomation2022 @karlheinz2000 @pixeldoc2000 Thank you for your care and your commitment. I was on vacation and didn't have much time. But with the last update it works for me now too.

@patience4711
Great work, the module just keeps getting better and better