search

ptrbojko / openhab-lsw4inverter-binding

6 stars 0 forks source link

Thing is not refreshing values on Deye #17

Closed chschilling closed 2 months ago

chschilling commented 4 months ago

Hey,

thanks for implementing the Deye Beta Support.

from initial testing, it seems to offer correct values so far.

But I have an issue, getting values refreshed...

I set refresh time to 15 seconds

When I disable/enable the thing, it sometimes gets actual values from Inverter and they seem to be correct so far. But after that, values are not changing anymore.

Just as information, I installed the Addon via jar file but the official addon was installed before, if that could be an issue anyhow.

I changed logging to trace:

openhab.log


2024-03-15 11:49:11.134 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:11.137 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Initial to process
2024-03-15 11:49:11.138 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Initial
2024-03-15 11:49:11.141 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Initial
2024-03-15 11:49:11.144 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:11.155 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 4 messages 0
2024-03-15 11:49:11.156 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:49:11.157 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:49:11.159 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:49:11.161 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:11.162 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:49:11.163 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:49:11.164 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 3 messages 0
2024-03-15 11:49:11.165 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:11.166 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:49:11.168 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:49:11.168 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:11.464 [DEBUG] [swlogger.internal.connection.Channel] - Received 36 bytes
2024-03-15 11:49:11.466 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 3 messages 1
2024-03-15 11:49:12.093 [DEBUG] [swlogger.internal.connection.Channel] - Received 282 bytes
2024-03-15 11:49:12.095 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 2 messages 2
2024-03-15 11:49:12.409 [DEBUG] [swlogger.internal.connection.Channel] - Received 43 bytes
2024-03-15 11:49:12.410 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 1 messages 3
2024-03-15 11:49:13.009 [DEBUG] [swlogger.internal.connection.Channel] - Received 15 bytes
2024-03-15 11:49:13.010 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 0 messages 4
2024-03-15 11:49:26.168 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-15 11:49:26.170 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-15 11:49:26.172 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 0 messages 4
2024-03-15 11:49:26.174 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-15 11:49:26.177 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-15 11:49:26.180 [DEBUG] [otocolv5.AbstractDataResponseHandler] - Trying to extract message, length 282 bytes
2024-03-15 11:49:26.197 [DEBUG] [ternal.protocolv5.ResponseDispatcher] - Handler class org.openhab.binding.lswlogger.internal.protocolv5.modbus.ByteBufferConsumer matched response
2024-03-15 11:49:26.200 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-15 11:49:26.205 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-15 11:49:26.210 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:26.212 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
2024-03-15 11:49:26.214 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:26.216 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:49:26.217 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:49:26.219 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:49:26.220 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:26.222 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:49:26.225 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:49:26.227 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:49:26.228 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:26.229 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:49:26.230 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:49:26.231 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:41.230 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-15 11:49:41.232 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-15 11:49:41.232 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:49:41.233 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:41.234 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
2024-03-15 11:49:41.235 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:41.236 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:49:41.236 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:49:41.238 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:49:41.238 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:41.239 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:49:41.240 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:49:41.241 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:49:41.242 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:41.243 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:49:41.244 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:49:41.244 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:56.244 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-15 11:49:56.245 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-15 11:49:56.247 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:49:56.248 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:56.249 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
2024-03-15 11:49:56.251 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:56.252 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:49:56.253 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:49:56.255 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:49:56.257 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:49:56.258 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:49:56.259 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:49:56.261 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:49:56.262 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:49:56.263 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:49:56.265 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:49:56.266 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:11.265 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-15 11:50:11.267 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-15 11:50:11.268 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:50:11.270 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:50:11.271 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
2024-03-15 11:50:11.272 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:11.273 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:50:11.275 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:50:11.277 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:50:11.278 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:11.279 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:50:11.280 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:50:11.282 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:50:11.283 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:50:11.285 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:50:11.286 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:50:11.287 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:26.286 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-15 11:50:26.288 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-15 11:50:26.289 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:50:26.290 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:50:26.292 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
2024-03-15 11:50:26.293 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:26.294 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Sending request to process
2024-03-15 11:50:26.295 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Sending request
2024-03-15 11:50:26.297 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Sending request
2024-03-15 11:50:26.299 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-15 11:50:26.300 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Receiving  to process
2024-03-15 11:50:26.301 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Receiving 
2024-03-15 11:50:26.303 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 4 messages 0
2024-03-15 11:50:26.304 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-15 11:50:26.305 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-15 11:50:26.307 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-15 11:50:26.308 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process

events.log:

2024-03-15 11:49:11.108 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lswlogger:Deye01:a38e1f2f44' changed from UNINITIALIZED (DISABLED) to INITIALIZING
2024-03-15 11:49:11.134 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lswlogger:Deye01:a38e1f2f44' changed from INITIALIZING to UNKNOWN
2024-03-15 11:49:26.180 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lswlogger:Deye01:a38e1f2f44' changed from UNKNOWN to ONLINE
2024-03-15 11:49:26.193 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Deye_beta_Total_output_power' changed from 65 W to 78 W
2024-03-15 11:49:26.201 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Deye_beta_PV1_current' changed from 0.699999988079071 A to 0.800000011920929 A
2024-03-15 11:49:26.206 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Deye_beta_PV2_current' changed from 0.800000011920929 A to 0.8999999761581421 A

If I could offer any more information, let me know :)

Greets Christian

Ichwersonsttttttttttttttttttttt commented 3 months ago

Same her. When you restart the Thing -> your Items get a update with the right value ?

ptrbojko commented 3 months ago

It seems that either the binding does not (1) request correctly for next data, or does not (2) read correctly the next data or the deye inverters (3) do not respond for consecutive requests.

I guess (2) is most probable cause. I have spotted some possible bug in the code for this - https://github.com/ptrbojko/openhab-lsw4inverter-binding/blob/8b77458685bef009037a129e0cfac9baac7fdbdb/src/main/java/org/openhab/binding/lswlogger/internal/connection/Channel.java#L64

ptrbojko commented 3 months ago

Could you kindly check following version https://drive.google.com/file/d/1_jh84I7J4X_cY9aU1RZUHWJ6w2iapyEE/view?usp=drive_link

chschilling commented 3 months ago

Hmm, unfortunatly, still no change.

here is a successfull request after disable / enable, but it took some minutes until I got this

2024-03-21 13:25:25.446 [DEBUG] [ernal.protocolv5.states.StateMachine] - Trying to schedule task in 15 SECONDS during state Receiving 
2024-03-21 13:25:25.448 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Receiving 
2024-03-21 13:25:25.449 [DEBUG] [ernal.protocolv5.states.StateMachine] - Waiting for state to process
2024-03-21 13:25:32.410 [DEBUG] [swlogger.internal.connection.Channel] - Received 282 bytes
2024-03-21 13:25:32.412 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 3 messages 1
2024-03-21 13:25:40.448 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Receiving ] to process
2024-03-21 13:25:40.449 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Receiving ]
2024-03-21 13:25:40.451 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 2 messages 1
2024-03-21 13:25:40.452 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-21 13:25:40.454 [DEBUG] [otocolv5.AbstractDataResponseHandler] - Trying to extract message, length 282 bytes
2024-03-21 13:25:40.465 [DEBUG] [ternal.protocolv5.ResponseDispatcher] - Handler ByteBufferConsumer [headerSize=28, firstAddress=3, lastAddres=128, mrs=[org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@1db4bd3, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@4c2bec, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@fc1bf1, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@10c2d7b, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@26fda, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@1fc32bd, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@1b99aa0, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@11a1c99, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@5bd3df, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@106b33, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@11592cb, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@5aba64, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@1d405b, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@1a9fe18, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@91ac2c, org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition@16bb380]] matched response
2024-03-21 13:25:40.466 [DEBUG] [otocolv5.states.ReadingResponseState] - No message to read, trying to schedule next read or switching to next state
2024-03-21 13:25:40.467 [DEBUG] [ernal.protocolv5.states.StateMachine] - Leaving Wrapper [Receiving ]
chschilling commented 3 months ago

grafik It seems that from time to time, a new value is received

ptrbojko commented 3 months ago

@chschilling could you elaborate more on this? Some more comprehensive logs, like covering some 5-10 minutes? Confirming that it more or less works let me publish changes and make new release.

Ichwersonsttttttttttttttttttttt commented 3 months ago

The green line is from a HTTP URL Thing from the SUN600. the blue from the lswlogger beta thing

image

Mar 23 10:56:41 openhabian karaf[613763]: Exception in thread "Thread-121" java.lang.NullPointerException: Cannot invoke "java.nio.ByteBuffer.clear()" because "buffer" is null
Mar 23 10:56:41 openhabian karaf[613763]: #011at org.openhab.binding.lswlogger.internal.connection.Channel.listen(Channel.java:72)
Mar 23 10:56:41 openhabian karaf[613763]: #011at org.openhab.binding.lswlogger.internal.connection.Channel$2.completed(Channel.java:82)
Mar 23 10:56:41 openhabian karaf[613763]: #011at org.openhab.binding.lswlogger.internal.connection.Channel$2.completed(Channel.java:73)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:129)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.UnixAsynchronousSocketChannelImpl.finishRead(UnixAsynchronousSocketChannelImpl.java:447)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.UnixAsynchronousSocketChannelImpl.finish(UnixAsynchronousSocketChannelImpl.java:195)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.UnixAsynchronousSocketChannelImpl.onEvent(UnixAsynchronousSocketChannelImpl.java:217)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.EPollPort$EventHandlerTask.run(EPollPort.java:306)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:113)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
Mar 23 10:56:41 openhabian karaf[613763]: #011at java.base/java.lang.Thread.run(Thread.java:840)
ptrbojko commented 3 months ago

@Ichwersonsttttttttttttttttttttt could tell what is your refresh time in a thing config? If more than 10 seconds - could you lower it to 5-6 seconds?

chschilling commented 3 months ago

I changed refresh time to 5 seconds.

it seems totaly random, if the thing gets new values and if not.

and at least on my side, it seems that it gets stuck after some few valuerefreshs

image

Ichwersonsttttttttttttttttttttt commented 3 months ago

@Ichwersonsttttttttttttttttttttt could tell what is your refresh time in a thing config? If more than 10 seconds - could you lower it to 5-6 seconds?

grafik

i set it now to 5 sec

i thing: Mar 23 10:56:41 openhabian karaf[613763]: Exception in thread "Thread-121" java.lang.NullPointerException: Cannot invoke "java.nio.ByteBuffer.clear()" because "buffer" is null

thats the problem

ptrbojko commented 3 months ago

I've made some adjustments, please check following version - https://drive.google.com/file/d/1_jh84I7J4X_cY9aU1RZUHWJ6w2iapyEE/view?usp=drive_link

Please set refresh time in thing config to at least 120 seconds (180?).

This is half baked version, only to check a theory on why buffers for messages are running out. Deye inverter is sending far more messages than other inverters...

chschilling commented 3 months ago 
2024-03-28 09:02:54.857 [DEBUG] [ernal.protocolv5.states.StateMachine] - Taken state Wrapper [Wrapper [Wrapper [Wrapper [Wrapper [Wrapper [Receiving ]]]]]] to process
2024-03-28 09:02:54.859 [DEBUG] [ernal.protocolv5.states.StateMachine] - Entering Wrapper [Wrapper [Wrapper [Wrapper [Wrapper [Wrapper [Receiving ]]]]]]
2024-03-28 09:02:54.860 [DEBUG] [swlogger.internal.connection.Channel] - Consuming messages, buffers 0 messages 4
2024-03-28 09:02:54.861 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-28 09:02:54.864 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-28 09:02:54.864 [DEBUG] [swlogger.internal.connection.Channel] - Received 279 bytes
2024-03-28 09:02:54.866 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 0 messages 3
2024-03-28 09:02:54.868 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-28 09:02:54.871 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-28 09:02:54.874 [DEBUG] [otocolv5.states.ReadingResponseState] - Trying to read a message
2024-03-28 09:02:54.877 [DEBUG] [otocolv5.AbstractDataResponseHandler] - Trying to extract message, length 279 bytes
2024-03-28 09:02:54.880 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.ArrayIndexOutOfBoundsException: Index 278 out of bounds for length 5
    at org.openhab.binding.lswlogger.internal.bytebuffer.ExtractingBuilder$ShortExtractor.lambda$mappedTo$3(ExtractingBuilder.java:75) ~[?:?]
    at java.util.function.Function.lambda$andThen$1(Function.java:88) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegisterDefinitionBuilder.lambda$add$0(ModbusRegisterDefinitionBuilder.java:37) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.modbus.ModbusRegistryValueDefinition.accept(ModbusRegistryValueDefinition.java:41) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.modbus.ByteBufferConsumer.lambda$accept$0(ByteBufferConsumer.java:35) ~[?:?]
    at java.util.ArrayList.forEach(ArrayList.java:1511) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.modbus.ByteBufferConsumer.accept(ByteBufferConsumer.java:26) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.AbstractDataResponseHandler.extract(AbstractDataResponseHandler.java:40) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.AbstractDataResponseHandler.handle(AbstractDataResponseHandler.java:29) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.ResponseDispatcher.accept(ResponseDispatcher.java:32) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.states.ReadingResponseState$ReadingHandler.onRead(ReadingResponseState.java:69) ~[?:?]
    at org.openhab.binding.lswlogger.internal.connection.Channel.read(Channel.java:131) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.states.ReadingResponseState$ReadingHandler.run(ReadingResponseState.java:62) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.states.StateMachine$MetaRunnableWrapper.handle(StateMachine.java:139) ~[?:?]
    at org.openhab.binding.lswlogger.internal.protocolv5.states.StateMachine.run(StateMachine.java:84) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]
2024-03-28 09:02:55.400 [DEBUG] [swlogger.internal.connection.Channel] - Received 8 bytes
2024-03-28 09:02:55.401 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 2 messages 1
2024-03-28 09:02:56.592 [DEBUG] [swlogger.internal.connection.Channel] - Received 43 bytes
2024-03-28 09:02:56.594 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 1 messages 2
2024-03-28 09:02:57.193 [DEBUG] [swlogger.internal.connection.Channel] - Received 15 bytes
2024-03-28 09:02:57.194 [DEBUG] [swlogger.internal.connection.Channel] - Listening for data, buffers 0 messages 3
ptrbojko commented 3 months ago

Another updates - https://drive.google.com/file/d/1_jh84I7J4X_cY9aU1RZUHWJ6w2iapyEE/view?usp=drive_link

Ichwersonsttttttttttttttttttttt commented 3 months ago

the point of -2000 was the switch to the googeldrive packet grafik

ptrbojko commented 3 months ago

I assume that this green line is a reading from the binding?

Ichwersonsttttttttttttttttttttt commented 3 months ago

I assume that this green line is a reading from the binding?

Yes , he get a update only when i start the addon / thing by hand new .

Can i help you , when i give you access to a Sun 600 inverter ?

ptrbojko commented 2 months ago

I've rewrite a little handling states and scheduling tasks. It turns out that in some cases whole bunch of tasks were cancelling without reason.

Please test following version - https://drive.google.com/file/d/1_jh84I7J4X_cY9aU1RZUHWJ6w2iapyEE/view?usp=drive_link

Please set refresh time to 50 or less.

chschilling commented 2 months ago

image looks quite promising for now!

I've changed refresh time to 30s, in the logs, it seems to get an update every second, tries to update every 30 seconds but graf in openhab is quite raw - Update for some minutes...

But at least, we do have values be refreshed now! Thanks so far ;)

chschilling commented 1 month ago

I would ask to not close directly :)

It seems that the thing is now refreshing every 5 minutes, nevertheless whats configured. Did you hardcode something for testing? Did you remove that part upstream so the new release is fine again?

Or do you implemented any other mechanism to set fixed updaterates?

I write into influx on change and it is quite exact 5 minutes between the changes, as said, configured for update is 30 seconds.

Greets and thanks!