Kostal Inverter Binding only working at Night

The Log, when starting in debug mode:

18:52:06.871 [INFO ] [b.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
18:52:06.940 [INFO ] [b.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_DE'.
18:52:40.130 [INFO ] [b.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
18:52:48.162 [INFO ] [re.automation.internal.RuleEngineImpl] - Rule engine started.
18:52:48.986 [INFO ] [org.openhab.ui.internal.UIService    ] - Started UI on port 8080
18:52:49.363 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'KOSTALPIKO1020_GridOutputPower' changed from NULL to 0.0
18:52:49.386 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'KOSTALPIKO1020_YieldDay' changed from NULL to 0.0
18:52:51.688 [INFO ] [hab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
18:52:52.991 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNINITIALIZED to INITIALIZING
18:52:53.018 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from INITIALIZING to UNKNOWN
18:52:53.324 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNKNOWN to OFFLINE (COMMUNICATION_ERROR)
18:52:53.332 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE

I send you a new dump file, with your last addon version.

Hi,
Hm, still is the third part missing.
Do you maybe could have a look at events.log at 19.00 and send to me.
I see that the first block values sent from inverter in capturing is from 19:00:44.
The two first dxsId’s are like 67109120 ( GridOutputPower) and 251658754 ( Yield Day ) and they both has values back from inverter. So I like to follow these two dxsId’s with regarded values in events.log too.

There is not much to see in the logs

openhabian@openhabian:/var/log/openhab $ cat openhab.log
2022-09-21 18:57:33.028 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
2022-09-21 18:57:33.104 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_DE'.
2022-09-21 18:58:11.881 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2022-09-21 18:58:19.073 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2022-09-21 18:58:20.590 [INFO ] [org.openhab.ui.internal.UIService   ] - Started UI on port 8080
2022-09-21 18:58:23.089 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
2022-09-21 19:02:25.152 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2022-09-21 19:02:27.626 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2022-09-21 19:02:31.964 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - QueuedThreadPool[OH-httpClient-common]@77413bb6{STOPPING,10<=0<=40,i=8,r=-1,q=0}[NO_TRY] Couldn't stop Thread[OH-httpClient-common-413,5,main]
2022-09-21 19:02:31.967 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - QueuedThreadPool[OH-httpClient-common]@77413bb6{STOPPING,10<=0<=40,i=8,r=-1,q=0}[NO_TRY] Couldn't stop Thread[OH-httpClient-common-414,5,main]
2022-09-21 19:02:36.081 [INFO ] [org.openhab.ui.internal.UIService   ] - Stopped UI
openhabian@openhabian:/var/log/openhab $ cat events.log
2022-09-21 18:58:20.908 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'KOSTALPIKO1020_GridOutputPower' changed from NULL to 0.0
2022-09-21 18:58:20.921 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'KOSTALPIKO1020_YieldDay' changed from NULL to 0.0
2022-09-21 18:58:24.255 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNINITIALIZED to INITIALIZING
2022-09-21 18:58:24.281 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from INITIALIZING to UNKNOWN
2022-09-21 18:58:34.702 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNKNOWN to OFFLINE
2022-09-21 18:58:34.711 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from OFFLINE to ONLINE
2022-09-21 18:59:34.708 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from ONLINE to UNKNOWN
2022-09-21 18:59:44.835 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNKNOWN to OFFLINE
2022-09-21 18:59:44.840 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from OFFLINE to ONLINE
2022-09-21 19:00:44.838 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from ONLINE to UNKNOWN
2022-09-21 19:00:54.957 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNKNOWN to OFFLINE
2022-09-21 19:00:54.961 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from OFFLINE to ONLINE
2022-09-21 19:01:54.964 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from ONLINE to UNKNOWN
2022-09-21 19:02:05.117 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from UNKNOWN to OFFLINE
2022-09-21 19:02:05.122 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'kostalinverter:piko1020:d9eb1a9425' changed from OFFLINE to ONLINE

I found this in the syslog file:

Sep 22 19:11:47 openhabian karaf[740]: entries = 2022-09-22T19:11:47.589726
Sep 22 19:11:57 openhabian karaf[740]: extentries = 2022-09-22T19:11:57.649831
Sep 22 19:12:57 openhabian karaf[740]: entries = 2022-09-22T19:12:57.696464
Sep 22 19:13:07 openhabian karaf[740]: extentries = 2022-09-22T19:13:07.750017
Sep 22 19:14:07 openhabian karaf[740]: entries = 2022-09-22T19:14:07.798394
Sep 22 19:14:17 openhabian karaf[740]: extentries = 2022-09-22T19:14:17.885778
Sep 22 19:15:01 openhabian CRON[18489]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Sep 22 19:15:17 openhabian karaf[740]: entries = 2022-09-22T19:15:17.932066
Sep 22 19:15:27 openhabian karaf[740]: extentries = 2022-09-22T19:15:27.985039
Sep 22 19:16:28 openhabian karaf[740]: entries = 2022-09-22T19:16:28.028352
Sep 22 19:16:38 openhabian karaf[740]: extentries = 2022-09-22T19:16:38.081552
Sep 22 19:17:01 openhabian CRON[18507]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Sep 22 19:17:38 openhabian karaf[740]: entries = 2022-09-22T19:17:38.125166
Sep 22 19:17:48 openhabian karaf[740]: extentries = 2022-09-22T19:17:48.174205
Sep 22 19:18:48 openhabian karaf[740]: entries = 2022-09-22T19:18:48.220690
Sep 22 19:18:58 openhabian karaf[740]: extentries = 2022-09-22T19:18:58.270914

This is the complete syslog file:

syslog.txt (946.4 KB)

Hi,
just uploaded a new one to GitHub - basse04/Test_02, Please try and send me the scrape and log files as usual.
Br Basse

I restarted openhab with the new addon at 17:15

You can use the same Download Link an Password as the last time. I created subfolders sorted by date.

Hi,
I can now follow all 3 requests with response every 60 seconds between 17:16:55 and 17:18:55.
I have found out that your inverter sends null for the dxsId’s regared to HomeConsumption, ( mine sends 0.000000 ) we have talked about this earlier, and I have also changed code to let the binding take care of this, but I have now found more lines in code also regarded to this. The binding somehow hangs when there is values like null involved. I have checked ( https://jsonformatter.org/json-editor ) the responsed Json strings and they looks all OK with or without null, but the binding will be balky.
It seems due to some of your scrapes that this happens during daytime, or proberly during some state like 3 / Feed in (MPP) and at other states sends something more like 0.
So Please, now try and see if you get some values to the Channels/Items. It might be that you have to delete old Channels/Items and set up new ones, after all we have done with the existing. Channels/Items

Wow. Nice. There are values in the items

Hi,
That is so good news.
I will then have this changes merged to the official version, there is some other fixes also which I have waited to merge.
I don’t know how long it will take, first I have to do my part and then will the openhab maintainers do checks, so Please use this one so far.
So it was the ‘null’ still making the problem, I just had to be convinced over that, some things take some time others more time than others.
I don’t remember if we have talked about the different UI and FW versions, I think we have.
I have an old paper with what I think is your versions and they are booth younger than mine, so I think that might be the reason.
Thank’s a lot for your patience and help, and if there is anything else regarded to this just let me know.
Br Basse

I have now installed your update in my productive openhab and it works there too.
I will use it until the official update is available.
Thank you very much for your effort. If it’s related to the new firmware, I’m sure more users will benefit from it in the future.