Packet execution timeout - Requeued.... Souliss Binding

Hi all,
on openhab2 log I noticed that every time I try to switch ON or OFF a light, there are 19 INFO log rows like that:

09:56:06.976 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued

It is due to the binding or something else (like firewall, OH2 or what else)? The commend is sent and light is switched ON or OFF but icon color doesn’t change.

Thank you.
Luca

I have a bit of a similar issue.
After restart of OH ist runs for several hours. I can control my devices, but I get also these timeour- Requed messages in the log.
Then after 4-8h it looks like the service stops. I get the following log entry:

2017-03-19 19:52:00.773 [WARN ] [org.apache.karaf.services.eventadmin] - EventAdmin: Blacklisting ServiceReference [{org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/*, service.pid=org.openhab.souliss, component.name=org.openhab.binding.souliss, component.id=155, service.id=290, service.bundleid=184, service.scope=bundle} | Bundle(org.openhab.binding.souliss_1.9.0 [184])] due to timeout! 

What can be done?
Is this an error in the binding?
Or can any of the souliss parameter can be adopted to fix this?

It seems that you have an issue on your configuration. If you see better
the message you can see a blank listing… It seems that openhab has
something of your configuration on a blacklist. Check your openhab
configuration.

Hmm, what should I check?
This is a new instllation of openhabian on my Raspi.
But I had the same behavor before on my test installation on a windows PC.

Did you follow this guide


?

Yes I did. I don’t think that the problem is in the nodes, because they still work with the Android app.
Just restarting Openhab solves the problem.

What I also see, is that the health status of the slave goes down from 255 -> 243 ->231 …
Do you know what these numbers mean?

these values show you the connection status of the slaves with the souliss
gateway. If these values start to going down and doesn’t come back high,
you have a problem on souliss programming and communication between slaves
and gatway. When these values go to the zero you will not able to use
souliss even with soulissApp because it means that slaves are not
communicating at all.

So the health status is something like the lost command rate?

Does it make sense to play wiht some of the settings in the souliss.cfg?
These are my current settings:


IP_LAN=192.168.178.49
USER_INDEX=72
NODE_INDEX=133
#SERVERPORT - Leave empty for casual port
SERVERPORT=

# time in mills
REFRESH_DBSTRUCT_TIME=600000
REFRESH_SUBSCRIPTION_TIME=120000
REFRESH_HEALTY_TIME=60000
REFRESH_MONITOR_TIME=2000
SEND_DELAY=1500
SEND_MIN_DELAY=100
SECURE_SEND_TIMEOUT_TO_REQUEUE=5000
SECURE_SEND_TIMEOUT_TO_REMOVE_PACKET=30000

I now ran a test.
I switched off my regular LED blinking every 10 seconds.
Then I switch my output on, and off.
The reaction of the slave node is ok, health status is 255.
In the log I see:

2017-03-20 22:35:17.049 [INFO ] [ding.souliss.internal.SoulissBinding] - receiveCommand - Node1REL1 = OFF - Typical: 0x11
2017-03-20 22:35:27.165 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:27.319 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:28.885 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:30.441 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:31.971 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:33.584 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:35.096 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:36.608 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:38.173 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:39.687 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:41.202 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:42.839 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:44.396 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:45.961 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:47.573 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:49.190 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:50.697 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:52.266 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:53.784 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:55.352 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:56.866 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:35:58.433 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:00.044 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:01.603 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:03.162 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:04.768 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:06.288 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:07.803 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:09.318 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:10.829 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:12.344 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:13.846 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:15.346 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:16.848 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Requeued
2017-03-20 22:36:18.349 [INFO ] [.internal.network.udp.SendDispatcher] - Packet Execution timeout - Removed
2017-03-20 22:43:11.392 [INFO ] [ding.souliss.internal.SoulissBinding] - receiveCommand - Node1REL2 = ON - Typical: 0x11
2017-03-20 22:43:14.224 [INFO ] [ding.souliss.internal.SoulissBinding] - receiveCommand - Node1REL2 = OFF - Typical: 0x11

It looks like a Requed command gets removed after a minute. The next command then gets executed.
But all this requeing should not be necessary, or am I wrong?

Now with not activation of the LEDs each 10s the system survived for the last 24h without restart :slight_smile: Too much traffic seems to be a problem.

I observed that switching an output on seems to work every time.
Switching off sometimes (not always) ends up in a requing sequence which then ends with “removed”.
The output is switched off, but the status information seems not to come back. My Icon in the Sitemap still lights on, and if I refresh the browser also the switch goes back to on.
I only get everything back to sync with switching on again and then off.

So what can I do?

Hello,

sorry for hijacking this thread, but I have the same problem.
Some items work, but most of them are getting requeued. The output changes, but openhab can`t see it.
The status gets updated, after the command has been requeued, removed, after approx.a minute.

Is there anything I could try to fix this ?

Thanks everyone