The log snippet you have shown does not include any obvious log for “button being hit”. What button? Is this some device, is there some rule as intermediary? Or is this a UI you are poking?
You’ll understand there is whole chain of actions here, some outside of openHAB, and you need to take an overview of the whole chain to see the problem area.
I’m trying both HABPanel and Paper UI. The inconsistency is the same on both. But it’s the same with a Zigbee sensor. I just walked into the kitchen. Less than one second for the lights to come on. That’s about 5m away and through 2 block walls. Just did the same for the utility room. 11 seconds. Probably a little bit closer and one block wall away. The lounge which is on a Zwave sensor:
LoungeSensor_MotionAlarm changed from OFF to ON
Nothing.
NightMode:
{
"link": "http://192.168.1.66:8080/rest/items/NightMode",
"state": "ON",
"editable": false,
"type": "Switch",
"name": "NightMode",
"label": "Night Mode",
"category": "Lighting",
"tags": [
"Lighting"
],
"groupNames": []
}
Lounge Lamp:
{
"link": "http://192.168.1.66:8080/rest/items/iLoungeLamp",
"state": "OFF",
"editable": true,
"type": "Switch",
"name": "iLoungeLamp",
"label": "Lounge Lamp",
"category": "Lighting",
"tags": [],
"groupNames": [
"gLounge"
]
}
Rule:
//Motion Lounge Night
rule MotionDetectedLoungeNight
when
Item LoungeMotion changed to ON
then
if ( NightMode.state == ON ) {
logInfo("Lounge", "Motion lounge")
iLoungeLamp.sendCommand(ON)
Timer60minLounge.sendCommand(ON)
}
end
This is where I hope you look at it and say “You forgot ‘x’ you muppet!”
Slow down. Fix one thing at a time, remember.
I’m not being arsey here, I’m offering the benefit of experience in how to fix multiple issues on a complex system I don’t fully understand.
Okay, the chain of events is quite obviously different for a motion triggered event and a UI commanded one.
Pick the simpler one - the UI command - and track that down.
If/when it’s mended, then see what’s left.
Right, point us to the already posted debug logs showing a delayed UI originated command.
1 Like
And a few minutes later with a new motion detect…
{
"link": "http://192.168.1.66:8080/rest/items/iLoungeLamp",
"state": "ON",
"editable": true,
"type": "Switch",
"name": "iLoungeLamp",
"label": "Lounge Lamp",
"category": "Lighting",
"tags": [],
"groupNames": [
"gLounge"
]
}
Working. I do wonder about this Xbee stick. Hopefully the Conbee will arrive on Sunday. I’ll add a couple of devices to that and see what sort of difference it makes.
If this is about the rule you started with here, I’ll note that it involves eight different commands, I assume at least some to real devices.
a) It takes a finite time to transmit, technology dependent.
b) Some bindings are better than others at handle a logjam.
But set that aside for now - I repeat my advice to concentrate on the simplest case, a single UI originating on/off, and show us detail.
No, this is the rule I posted just above. But looks like this:
//Motion Lounge Night
rule MotionDetectedLoungeNight
when
Item LoungeMotion changed to ON
then
if ( NightMode.state == ON ) {
logInfo("Lounge", "Motion lounge")
iLoungeLamp.sendCommand(ON)
Timer60minLounge.sendCommand(ON)
}
end
The one with 8 commands that you spotted my screwup with at the start is the one that worked instantly when I just went to the kitchen.
I think I’m going to hold fire now until the new stick arrives. There’s something funny about this Xbee, I’m sure of it.
Thank you so much for your help on this. I really don’t want to give up.
I’m surprised that works. Correct form -
rule "MotionDetectedLoungeNight"
The “name” of the rule does serve a function, and in passing, every rule must have a unique name.
Yes, I’ve seen some that have them. Usually if they put spaces in. Mine are half and half so I’ll put them all in quotes if that’s the way it should be.
If using one word as rule name it’s fine without quotes, so there should be no difference between
rule "MotionDetectedLoungeNight" and rule MotionDetectedLoungeNight, but it’s good style to keep the name in quotes 
Be sure that every rule has a unique name, even when the rules are in different files.
But that rule is something, you should really care about after caring about the latency.
- First step: connect one light to openHAB
- Second step: connect that light to a Switch Item
- Third step: Switch the Light through Paper UI control. Does that work without latency (i.e. not more than some 10 Milliseconds)?
- Fourth step: Place the Switch Item onto a sitemap. Does that Switch work without latency?
- Fifth step: connect a hardware Switch to openHAB (maybe a motion detector)
- Sixth step: connect that Switch to another Item.
- Seventh Step: take a look at the events.log when switching the switch. Does that work without latency? (see third step)
- Eighth step: connect both Switches through a rule.
- Ninth step: take another look at the events.log. you should see an event immediately when switching through the hardware switch, then after some 10 Milliseconds the Light should be turned on (through the rule).
And there’s the thing. I missed step 4. I don’t get sitemaps. I can’t see how to do that in any of the interfaces available.
Apart from that, I did 1, 2 and 3. Right from the outset I was seeing latency but figured it was because I only had one light with one sensor. I thought it was a network issue that would be resolved if I had more devices in the network.
Again, just walked into the kitchen and about 9 devices reacted instantly. Went through the utility room into the garden. The same type of sensor and the same type of bulb as I have 4 or 5 of in the kitchen. 10 seconds after I walk through the utility room and I’m out in the garden I see the utility light come on.
My Conbee should arrive tomorrow. I’m going to add one bulb through that and then one motion sensor. If that’s any better then I’ll start moving all the other devices over. If not, I’ve got an SD card with HomeAssistant on which I’ll try as well. If that’s the same then I’ll be moving everything back to SmartThings.
You seem to be using HABpanel. That’s fine, you have chosen to start witrh something more complex but it does essentially the same thing as BasicUI with a sitemap.
So don’t start off on yet another tangent.
Don’t care.
Focus on the simplest case; you told us you could experience delay when triggering directly from UI. Capture that problem, show us your evidence, or point to the evidence that you have posted before.
Ok, here’s an excerpt from the log:
2020-05-17 00:08:00.200 [ome.event.ItemCommandEvent] - Item 'iDiningRoomLamp' received command ON
2020-05-17 00:08:00.211 [nt.ItemStatePredictedEvent] - iDiningRoomLamp predicted to become ON
2020-05-17 00:08:00.226 [vent.ItemStateChangedEvent] - iDiningRoomLamp changed from OFF to ON
Now check out the movie:
And this:
Started as a conversation with Chris about one thing and shifted to latency. I uploaded a couple of log files including one quite big one.
It’s not a great dealof use on its own. “There was a command. Origin unknown, effects unknown.”
It would be useful combined with a simultaneous debug log to highlight the point to start looking.
Again, without some narrative about what you expected to happen and when, the value is limited.
At least we know it’s Zigbee.
I don’t know anything about Zigbee, nothing leaps out for me as sick here.
You do seem to have both ttyACM1 and ttyUSB0 ports configured as zigbee, the latter not working.
No, but it shows that the whole transaction seemed to occur in 0.026 of a second and then took 9 or 10 seconds to actually happen. You asked for evidence of the problem, I think the log and the video show that I’m not imagining things, making it up or expecting too much.
So, as far as I can see, that says OpenHAB did what it was told to do in double quick time. Then, either the Zigbee stick sat there and didn’t send the command for 10 seconds or the bulb sat there and ignored the command for 10 seconds, or maybe a combination of the 2. The fact that it happens regardless of the bulb makes me think that the Zigbee stick is the common denominator, hence ordering a different one.
I don’t know what’s what in terms of the log file I uploaded. I was asked to provide it and that’s what I did.
I suspect the 2 ports configured as Zigbee is down to the fact that I took the Xbee stick out and put a CC2531 in to see if that made a difference. At the time I downloaded the log, I think I’d swapped back to the Xbee and for some reason, even though I’d deleted it, the CC2531 stayed there and just said “Removing” or something for some time.
Are we talking about the events.log snip here? Let’s clarify -
2020-05-17 00:08:00.200 [ome.event.ItemCommandEvent] - Item 'iDiningRoomLamp' received command ON
2020-05-17 00:08:00.211 [nt.ItemStatePredictedEvent] - iDiningRoomLamp predicted to become ON
2020-05-17 00:08:00.226 [vent.ItemStateChangedEvent] - iDiningRoomLamp changed from OFF to ON
There’s an Item command. The log doesn’t tell us who done it or when, rule or UI action for example. That’s fine, you can tell us that. Please do so, when showing logs - “what does it show, what happened.”
The log cannot tell us if there is some delay between the rule or UI event and the command appearing in the log. You can probably estimate that, if it’s you poking UI buttons.
If not, and you feel this part might be delayed, we might have to construct some kind of parallel action to see what the timing is about.
Frankly, this part - UI action to openHAB - is not likely to be the problem and there is other stuff we can look at more easily first.
So, first line of log squeezed for info.
Next, a “prediction”. This is the autoupdate feature at work, pre-empting the command by guessing the effect it will have.
That prediction is actioned in the next line, and the Item state updated to the auto “guess”. Great, this gives a snappy UI responsiveness, which is not affected by any turnaround delays in something happening at a remote device.
By design, autoupdate hides the effects of any delay with your external devices.
The “transaction” here is a fantasy transaction, and as you say is all over in 26mS.
So the log boils down to - “there was a command”.
It shows us nothing about what or when the binding is up to, or when any response might come back from the remote device.
That’s all fine, that’s why we need to look at binding debug logs.
Readers here didn’t even know if this log is associated with one of your observed delays or not. Please tell us the circumstances when sharing logs, don’t wait for an inevitable interrogation.
I couldn’t get the video to work really. I don’t doubt you have problems, made all the more frustrating by being intermittent.
“Show us the evidence” is not “don’t believe you”, it is “give us info for diagnosis”
We’re on post #26 of this thread with no recent debug log given here.
We do now have a log available elsewhere, but it spans many hours. We have not been told if it includes any delay incidents, nor when they occurred. We have been told there is stick-swapping going on, how much chaos and distraction that might add in that particular log I don’t know.
I have no zigbee expertise, and it sure won’t be me diagnosing at that level. I did spend an hour trying to figure out the meaning of two-serial-port issue, and still wonder if a broken bridge Thing might add retry delays - I don’t think so.
I can tell what you can do to make it easier for an expert to look. Tell them where to look e.g. “at 10:20 I clicked on Lamp X in UI, and it took 8 secs to light up. Here is the Thing/channel details for Lamp X, here is the debug log for several hours.”
The video is probably what gives it the most context. It shows me switching the dining room light on on Paper UI and then the 10 second delay before the light comes on. The log is showing the same transaction.
Bear in mind your request:
Focus on the simplest case; you told us you could experience delay when triggering directly from UI. Capture that problem, show us your evidence, or point to the evidence that you have posted before.
The log elsewhere is what was asked for. I initially posted a shorter one and Chris said that it wasn’t enough. He said he could handle logs up to 10 or 20mb so I figured that it would be better if there was too much rather than too little again. He mentioned time spans from minutes to an hour or 2. I downloaded the current .log file as I was assuming that he uses something like his logfile analyser rather than going through it line by line. If I cut it at a certain point, I can guarantee that the bit that is needed will be just before or just after. But it will include delays because 99% of the transactions have a delay.
Adding the second bridge was an action to see if the Xbee was the cause of the delays. It’s not causing the delays because they were already there.
In the conversation with Chris, he asked for the logs and I provided them but have heard nothing since. I don’t expect to hear anything either. I’m not paying him. I have no right to his time. And that’s fine.
This is my current appraisal of the situation:
Fact - everything worked with SmartThings
Fact - very little works consistently with any stability with a Pi, a Zigbee stick and OpenHAB
Fact - the bits that have changed are the Pi, the Zigbee stick and OpenHAB
So, first thing to eliminate is the Zigbee stick. I’ll be doing that today. Next, I’ll try the same hardware with HomeAssistant. That eliminates OpenHAB. If that fails, my only realistic option is to go back to SmartThings and wait for this ecosystem to become more plug and play.
Have you been following this thread?
I saw that a few days ago when I started looking at the latency problems. My Conbee II stick arrived yesterday but, for some reason I just couldn’t get it working on OH. I already had another SD card with HomeAssistant on so I put that in and added the deConz addon. It immediately found the bulb and sensor I added. The response time was instantaneous when using the interface, faster even that SmartThings. I thought ST was quick but there is still probably time to blink between tapping a switch on the UI and the light coming on. With HA, there is no time to even blink. Same with a motion sensor. I checked and HA uses channel 15 by default. I wonder if that’s the issue at my end.
In all honesty, adding in the bulbs and sensors with HA was MUCH easier than OH. Took me about an hour to add in 16 lights, 2 outlets and 4 sensors. Maybe that was down to the channel too but there were 2 SmartThings motion sensors that OH just would not find, even though 2 identical sensors were fine.
I like OH in terms of UI compared with HA. And HABPanel is infinitely better than anything I’ve seen on HA. But at the end of the day, I need my devices to be supported and to do what they’re told when they’re told. So for me, it’s au revoir OpenHAB.
Thank you for your help on this!
Bye then.
