Experiencing occasional Random delay in rule execution

Oh okay. I am obviously unfamiliar with what you are referring to then. Can you explain?

The JavaVM (I assume you don’t mean that by “VM”, do you?) is multithreaded, so openHAB runs multithreaded. There’s parameters to change in $USER_DATA/etc/* how many threads to use/have ready for use.

No, I mean virtual machine as seen by Proxmox, my hypervisor.

Okay thank you. I will look tonight to see if I can change the settings in that file. Is there an explanation on how to do this somewhere?

That’s a whole bunch of files. I think the parameters are not documented. There were discussions on the forum I don’t find right now.
But you would need to have a pretty unusual set of rules if it didn’t work with the default settings so I don’t think it’s the reason.
I’d look into the zwave network first. Add some debug outputs to better track what rules run when.
Another thing comes to mind: do you edit rules or items in place ? You shouldn’t. Processing of changes can queue up. You would see java use >= 100% CPU.

Hi @TheJM,

Out of interest what Hypervisor are you using? You describe your VM as 1 core and 2 threads, this is very unfamiliar to me. This could just be the terminology your using. I’m not aware of any Hypervisor that allow you specify the number of threads your VM will be able to use. Besides just running the OS is likely to take 25/30 threads especially while booting.

I would suggest a configuration of 4 vCPU’s spread across two physical cores and a 1Gb of RAM per core used. Having too much RAM is just as bad as not having enough.

Cheers,

Garry

I apologize as my terminology probably wasnt correct (I am new to the hypervisor world). I am using Proxmox VE. I have a 9900k with 8 cores, 16 threads. The VMs see that as 16 vCPUs so in my case 1vCPU=1thread.

I will do that.

I believe you mentioned that 2.5 has some more z-wave features than 2.4 did. Would you recommend me upgrading and then troubleshooting? Also, are there any best practices to do before upgrading (besides making a backup)? Just dont want to lose the majority of my configs.

Thank you for your help.

I’d upgrade first. Backup your config (openhab-cli backup ...)

A single vCPU is more than enough. 4 GB is reasonable for x86-64bit. That usually takes 4 times the amount of ARM/32bit, and 1GB on a RasPi is the minimum it takes OH to run well.

Your use of the term “Threads” is unusual and overlaps with other meanings for the term. In an OH context, there are a number of thread pools that OH pulls from to run just about everything. By default, the thread pool for Timers is of size 2 and Rules is of size 5. If you have more Rules than there are threads available in the pool trying to run at the same time, the later ones will have to wait until a thread frees up.

These have nothing to do with your VM “threads”.

See Why have my Rules stopped running? Why Thread::sleep is a bad idea for a full explanation.

But I tend to agree that your problem may not be related to this assuming you have no other long running or blocking commands like executeCommandLine or sendHttp*Request.

Depending on the Hypervisor and physical hardware being used as the host, your not likely to be able to address more than a Gb of RAM at a time. In addition memory addressed by Hypervisors is divided across the CPU bus, so you need to make sure that you have a minimum of two vCPU’s and they are spread even across physical sockets. But were now heading way off topic.

So I upgraded to 2.5 and enabled debugging and found an issue with a couple of my rules doing this not im not sure what im looking for.

I actually just had another incident where a rule didn’t work properly. I have a daytime scene and it turns on and off several lights. It works almost every time but this time, one of the lights didn’t turn on. After checking the logs, it looks normal. The Kitchen Pendant lights are the one that didn’t actually turn on. It looks normal.

Like i said above, i don’t see anything weird in the logs. What should i be looking for?

2019-09-15 10:03:32.373 [ome.event.ItemCommandEvent] - Item ‘DummyDaytimeScene’ received command ON

2019-09-15 10:03:32.375 [vent.ItemStateChangedEvent] - DummyDaytimeScene changed from OFF to ON

2019-09-15 10:03:32.378 [ome.event.ItemCommandEvent] - Item ‘ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer’ received command 100

2019-09-15 10:03:32.381 [ome.event.ItemCommandEvent] - Item ‘ZWave007HallwayRecessedLightsDimmerSwitchSwitchDimmer’ received command 100

2019-09-15 10:03:32.382 [nt.ItemStatePredictedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer predicted to become 100

2019-09-15 10:03:32.384 [ome.event.ItemCommandEvent] - Item ‘ZWave008GreatRoomSwitchLampDimmerSwitchSwitchDimmer’ received command 100

2019-09-15 10:03:32.390 [ome.event.ItemCommandEvent] - Item ‘ZWave010KitchenPendantLightsDimmerSwitchSwitchDimmer’ received command 50

2019-09-15 10:03:32.391 [ome.event.ItemCommandEvent] - Item ‘ZWave009KitchenRecessedLightsDimmerSwitchSwitchDimmer’ received command 100

2019-09-15 10:03:32.394 [ome.event.ItemCommandEvent] - Item ‘ZWave020GreatRoomLightDimmerSwitchSwitchDimmer’ received command 100

2019-09-15 10:03:32.396 [ome.event.ItemCommandEvent] - Item ‘ZWave019MasterBedroomFoyerLightDimmerSwitchSwitchDimmer’ received command OFF

2019-09-15 10:03:32.398 [ome.event.ItemCommandEvent] - Item ‘ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer’ received command OFF

2019-09-15 10:03:32.399 [ome.event.ItemCommandEvent] - Item ‘DummyDaytimeScene’ received command OFF

2019-09-15 10:03:32.399 [nt.ItemStatePredictedEvent] - ZWave007HallwayRecessedLightsDimmerSwitchSwitchDimmer predicted to become 100

2019-09-15 10:03:32.405 [nt.ItemStatePredictedEvent] - ZWave008GreatRoomSwitchLampDimmerSwitchSwitchDimmer predicted to become 100

2019-09-15 10:03:32.408 [vent.ItemStateChangedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer changed from 0 to 100

2019-09-15 10:03:32.408 [nt.ItemStatePredictedEvent] - ZWave010KitchenPendantLightsDimmerSwitchSwitchDimmer predicted to become 50

2019-09-15 10:03:32.410 [nt.ItemStatePredictedEvent] - ZWave009KitchenRecessedLightsDimmerSwitchSwitchDimmer predicted to become 100

2019-09-15 10:03:32.411 [nt.ItemStatePredictedEvent] - ZWave020GreatRoomLightDimmerSwitchSwitchDimmer predicted to become 100

2019-09-15 10:03:32.413 [nt.ItemStatePredictedEvent] - ZWave019MasterBedroomFoyerLightDimmerSwitchSwitchDimmer predicted to become OFF

2019-09-15 10:03:32.415 [nt.ItemStatePredictedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer predicted to become OFF

You’re banging out a lot of commands in a few milliseconds.

Isolating node 6 from your events

2019-09-15 10:03:32.378 [ome.event.ItemCommandEvent] - Item ‘ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer’ received command 100
2019-09-15 10:03:32.382 [nt.ItemStatePredictedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer predicted to become 100
2019-09-15 10:03:32.398 [ome.event.ItemCommandEvent] - Item ‘ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer’ received command OFF
2019-09-15 10:03:32.408 [vent.ItemStateChangedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer changed from 0 to 100
2019-09-15 10:03:32.415 [nt.ItemStatePredictedEvent] - ZWaveNode006GarageEntryHallDimmerSwitchSwitchDimmer predicted to become OFF

you send it two commands within 20 milliseconds. I wouldn’t like to guess which one gets to your device first. It’s not necessarily the same order as they get processed in openHAB.

ZWave packet loss. You would need to enable debugging for the zwave binding.

Thanks, that was actually a typo. That light was only supposed to get one command, the off command.

Ill take a look at that. thank you!

Okey dokey. You are still banging out six commands in 20 milliseconds, it’s something of a stress test.

I have several scenes that turn on and off several lights. For instance, my “Leaving Scene” turns off all of my indoor lights. I have other scenes that turn most of the lights off but certain ones on.

In cases where I am activating multiple lights at once, should i put a small delay between them? like Thread::sleep(100ms)?

No. Let the lower protocol layers serialize and handles these commands.

On the practical side, it would be interesting to temporarily find out if it did help. But yes, the binding should be running a queue, as required by the technology involved.

Where that goes wrong is when the tech involved is “fire and forget”, i.e. the binding cannot tell if a command gets lost in a poorly performing network, and so is unable to retry. That applies whether you are sending commands quickly or slowly, of course. But maybe ‘quickly’ actually adds to the poor performance.