[SOLVED] How can I increase Openhab2 writes operations into MQTT?

sbeex · December 26, 2018, 5:08pm

Platform information::

Hardware: Raspberry PI 3

OS: raspbian

Java Runtime Environment: 1.8.0_191

openHAB version: 2.4.0

use MQTT embedded (but had the same issue with Mosquito days ago with openhab 2.1)

Context:
I would like to turn on bathroom lights (sonoff) when someone enter (philips hue motion sensor)
I wrote a small rule for that:


rule "Movement detected in bathroom"
when
    Item BathroomPresence changed
then
    // presence detected
    if(BathroomPresence.state == ON) {
        if(BathroomPresenceTimer.state != ON){
            logInfo("bahtroom.presence", "Movement detected in bathroom (timer were not started so start it)");
            BathroomPresenceTimer.sendCommand(ON);
            BathroomPresenceTimer.postUpdate(ON); // start the timer if not already active
        } else {
            logInfo("bathroom.presence", "Movement detected in bathroom (timer already started)");
        }
    }

    // probably left the room
    else if(BathroomPresence.state == OFF){
        if(BathroomPresenceTimer.state != OFF){ 
            logInfo("bathroom.presence", "No more mouvement detected in bathroom but timer active");
        } else {
            logInfo("bathroom.presence", "No more mouvement detected in bathroom and timer inactive");
        }
    }
end

rule "Bathroom presence timer started"
when
    Item BathroomPresenceTimer received command ON 
then 
        logInfo("bathroom.presence", "movement detected turn the light on and start a timer for x minutes");
        BathroomLight.postUpdate(ON)
        BathroomLight.sendCommand(ON)
        BathroomMirrorLight.postUpdate(ON)
        BathroomMirrorLight.sendCommand(ON)

            if(now.getHourOfDay() >= 6 && now.getHourOfDay() < 22){
                logInfo("bathroom.presence", "It is " + now.getHourOfDay() + "h, musicmaestro!");

                if(now.getHourOfDay() >= 9 && now.getHourOfDay() < 20){
                    BathroomSonosVolume.sendCommand(new PercentType(25));
                } else {
                    BathroomSonosVolume.sendCommand(new PercentType(10));
                }
 
                sendCommand(BathroomSonosRadioTuneIn, "2109"); // 2109 funradio

                if(now.getHourOfDay() >= 9 && now.getHourOfDay() < 20){
                    BathroomSonosVolume.sendCommand(new PercentType(25));
                } else {
                    BathroomSonosVolume.sendCommand(new PercentType(10));
                }
            } else {
                logInfo("bathroom.presence", "no music it's too late"); 
            }
end

Unfortunately it takes up to 5 seconds sometimes just to turn on the lights.

I investigated the following points:
1. Maybe the sonoff reacts too late to MQTT bus ?

No it’s very fast

I connected MQTT.fx (mqtt client) directly to the mqtt bus and tried to publish manually some messages to turn the lights on (sonoff) → it reacts immediatly. This exclude the sonoff potential issue.

2. Rule engine or presence detection is slow ?
It looks like it’s not the problem based on following tests:

- I tried to trigger OpenHab UI switch to see if it’s long to publish on MQTT and… it is unfortunately quite slow 2-3 seconds.

** 3. Is it related to raspberry pi resources ? **
I won’t say it’s not but if I run htop most of the time cpus are not all working and memory: 488/927

Question: Can we improve this writing delay ?

I would like to increase this time so we reach max 1 second between the click on the UI and the MQTT publish. It should drastically improve the user experience.

Any help is really appreciated thank you in advance

vzorglub · December 26, 2018, 8:47pm

Not related, but why are you doing this?

        BathroomLight.postUpdate(ON)
        BathroomLight.sendCommand(ON)
        BathroomMirrorLight.postUpdate(ON)
        BathroomMirrorLight.sendCommand(ON)

This shoud suffice:

        BathroomLight.sendCommand(ON)
        BathroomMirrorLight.sendCommand(ON)

You say you have a problem with the MQTT publishing delay but you didn’t post your items…

sbeex · December 26, 2018, 9:46pm

I added postUpdate(ON) because sometimes the UI were not updated otherwise IIRC.

Regarding my items here they are if you think it may help:

//bathroom.items
// Salle de bain (deb)
Number BathroomTemperature "Température salle de bain (deb) [%.1f °C]" <temperature> (Bathroom, gTemperature, gTemperatureIndoor) { http="<[hueMotionSensor8Temperature:60000:JS(getHueTemperature.js)]" }
DateTime BathroomTemperatureLastMeasure "Derniere mesure température [%1$td.%1$tm.%1$tY   %1$tH:%1$tM]" <time> (Bathroom) { http="<[hueMotionSensor8Temperature:60000:JS(getHueLastChange.js)]" }
//Switch BathroomPresence "presence salle de bain (deb) [%s] " <motion> (Bathroom, gMotion) { http="<[hueMotionSensor8Presence:1500:JS(getHuePresence.js)]" }
Switch BathroomPresence "presence salle de bain (deb) [%s]" <motion> (Bathroom, gMotion) {channel="hue:0107:00178821645b:35:presence"}
DateTime BathroomPresenceLastMeasure "Dernière présence détectée [%1$td.%1$tm.%1$tY   %1$tH:%1$tM]" <time> (Bathroom, gMotion) { http="<[hueMotionSensor8Presence:5000:JS(getHueLastChange.js)]" }
Number BathroomLuminosity "Luminosité [%.1f Lux]" <light> (Bathroom, gLight) { http="<[hueMotionSensor8Illuminance:15000:JS(getHueIlluminance.js)]" }
DateTime BathroomLuminosityLastMeasure "Derniere mesure luminosité [%1$td.%1$tm.%1$tY   %1$tH:%1$tM]" <time> (Bathroom, gLight)  { http="<[hueMotionSensor7Illuminance:15000:JS(getHueLastChange.js)]" }
Switch BathroomDarkness "darkness" <moon> (Bathroom) { http="<[hueMotionSensor8Illuminance:15000:JS(getHueDark.js)]" }
Switch BathroomDayLight "daylight" <sun> (Bathroom) { http="<[hueMotionSensor8Illuminance:15000:JS(getHueDaylight.js)]" }
Number BathroomHueSensorBatteryLevel "Batterie capteur hue [%s]" <battery> (Bathroom) { http="<[hueMotionSensor8Temperature:60000:JS(getHueBatteryLevel.js)]" }

Switch BathroomMirrorLight "Lampe mirroir sdb (deb)"  <light> (Bathroom)    [ "Switchable" ]   {channel="mqtt:topic:b4d43d12:enabled"} // SONOFF7
Switch BathroomLight "Lampe plafond sdb (deb)"  <light> (Bathroom)    [ "Switchable" ]   {channel="mqtt:topic:ab6566d0:enabled"} // SONOFF8
Switch BathroomPresenceTimer "Timer présence actif sdb [%s]" <time> (Bahtroom) { expire="7m,command=OFF" }  
Dimmer BathroomSonosVolume "Volume salle de bain [%.1f %%]" <soundvolume>      (Bathroom, gSpeaker) {channel="onos:PLAY1:RINCON_5CAAFDC20C5801400:volume"}
String BathroomSonosRadio  "Radio [%s]" <sonos_radio>        (Bathroom)                {channel="sonos:PLAY1:RINCON_5CAAFDC20C5801400:radio"}
String BathroomSonosRadioTuneIn  "Tunein [%s]" <sonos_radio>        (Bathroom)                 {channel="sonos:PLAY1:RINCON_5CAAFDC20C5801400:tuneinstationid"}

vzorglub · December 26, 2018, 9:53pm

Switch BathroomMirrorLight "Lampe mirroir sdb (deb)"  <light> (Bathroom)    [ "Switchable" ]   {channel="mqtt:topic:b4d43d12:enabled"} // SONOFF7
Switch BathroomLight "Lampe plafond sdb (deb)"  <light> (Bathroom)    [ "Switchable" ]   {channel="mqtt:topic:ab6566d0:enabled"} // SONOFF8

These two. You are using MQTTv2 binding. This is a very new binding and you may have come across a bug.
Can you post the detailed confid of these two items, s’il te plais.

Have you put these two items in a sitemap and how long does they take to turn on?

sbeex · December 26, 2018, 10:01pm

Indeed I had to upgrade since 2.4 and wanted to use the new way of doing as it looks less “hands on” than the OH 1 implementation.

So about the config for theses two items:

Here is my sitemap:

// home.sitemap
sitemap home label="Home" {
    Frame {
		Text label="Corridor" icon="corridor" {
			Frame {
				Default item=CorridorTemperature
				Default item=CorridorLuminosity
				Default item=CorridorPresence
				Default item=CorridorLamp
				Default item=CorridorPresenceTimer
			}
		}
		Text label="Cuisine" icon="kitchen" {
			Frame {
				Default item=KitchenTemperature
				Default item=KitchenLuminosity
			}
		}
		
		Text label="Salon" icon="sofa" {
			Frame {
				Default item=LivingRoomAquaponieTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LivingRoomSofaTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LunchRoomTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]


			//	Default item=LivingRoomSofaSonosVolumePlayOne1
			//	Default item=LivingRoomSofaSonosVolumePlayOne2
			//	Default item=LivingRoomSofaSonosVolumePlaybar
			}
			Frame label="Multimedia" {
				Default item=LivingRoomSofaSonosVolume
				Default item=LivingRoomSofaSonosSub 
				Switch item=NetflixProfileSelector mappings=[3="Seb", 4="Deb"]
				Switch item=AppleTVRemote mappings=["Volume Up"="Volume +","Volume Down"="Volume -"]
			}
		}
		
        Text label="Dressing" icon="wardrobe" {
			Default item=DressingTemperature
			Default item=DressingLuminosity
			Default item=DressingLampOne
			Default item=DressingLampTwo
		}
		Text label="Bureau" icon="office" {
			Frame  {
				Default item=OfficeTemperature
				Default item=OfficeLuminosity
				Default item=OfficeSonosVolume
				Default item=OfficeBatmanLampState
				Default item=OfficeBatmanLampColor
				Default item=OfficeLamp
				Default item=OfficeFan
				Switch  item=OfficePlaylists mappings=[0="Aucun", 1="Classic", 2="Epic", 3="Motivation"]
				Default item=OfficeSonosPlayer
				Image item=OfficeSonosCover
				Default item=OfficeHueSensorBatteryLevel visibility=[OfficeHueSensorBatteryLevel<30] valuecolor=[OfficeHueSensorBatteryLevel>=30="green", <30="red"]
				Default item=OfficePresenceTimer
				Default item=OfficeComputerPower 
				Default item=OfficeComputerPowerCurrentVoltage 
				Default item=OfficeComputerPowerCurrentAmperage
				Default item=OfficeComputerPowerCurrentPower 
				Default item=OfficeComputerPowerConsumedToday
				Text label="Autres" icon="" {
					Frame {
						Default item=OfficeHueSensorBatteryLevel valuecolor=[OfficeHueSensorBatteryLevel>=30="green", <30="red"]
						Default item=OfficePresence
						Default item=OfficePresenceLastMeasure
						Default item=OfficeTemperatureLastMeasure
					}
				}
			}
			Frame label="Appareils réseaux" {
				Text item=OfficePrinterStatus
				Text item=OfficeComputerStatus
			}
		}
		
		Text label="Salle de bain (grande)" icon="bath" {
			Frame {
				Default item=BathroomTemperature
				Default item=BathroomLuminosity
				Default item=BathroomPresence
				Default item=BathroomHueSensorBatteryLevel
				Default item=BathroomLight
				Default item=BathroomMirrorLight  
				Default item=BathroomPresenceTimer
				Default item=BathroomSonosVolume
				Default item=BathroomSonosRadio
								Default item=BathroomSonosRadioTuneIn
			}
		}
        Text label="Chambre à coucher" icon="bedroom_red" {
			Frame {
				Default item=BedroomTemperature
				Default item=BedroomLuminosity
				Default item=BedroomPresence
				Default item=BedroomHueSensorBatteryLevel
				Default item=BedroomLamp
				Default item=BedroomLampColor 
				Default item=BedroomTopLamp
				Default item=BedroomPresenceTimer
			}
		}
		Text label="Toilettes" icon="toilet" {
			Frame {
				Default item=WcTemperature
				Default item=WcLuminosity
				Default item=WcSonosVolume
				Default item=WcLight
				Default item=WcPresenceTimer
			}
		}
		Text label="Lessiverie" icon="washingmachine" {
			Frame {
				Default item=LaundryTemperature
				Default item=LaundryLuminosity
			}
		}
		Text label="Garage" icon="garage" {
			Frame {
				Default item=GarageTemperature
				Default item=GarageLuminosity
				Default item=GarageDoor
			//	Default item=GarageTemperatureLastMeasure 
			}
		}
	}
    
	Frame label="Global" {
		Selection  item=DominionDetectedSpirits icon="parents_3_3"  mappings=[0="None", 1="Seb", 2="Deb", 3="Seb & Deb"]
		Text label="Température" icon="temperature" {
			Frame label="Résumé" {
				Text item=gTemperatureIndoor valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Webview height=20 url="http://raspberrypi.fritz.box:3000/d/-57nvPWgz/temperature?orgId=1&from=1545770552562&to=1545772488638&theme=light&panelId=2&fullscreen"
			}
			Frame label="Pièces à vivre" {
				Default item=OfficeTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=WcTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=BathroomTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=BedroomTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=KitchenTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=DressingTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=CorridorTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LivingRoomAquaponieTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LivingRoomSofaTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LunchRoomTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=CorridorTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]

				
			}
			Frame label="Autres" {
				Default item=GarageTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
				Default item=LaundryTemperature valuecolor=[>=22="orange",>=19="green", <19="blue"]
			}
		}
		Text label="Eve" icon="" {
			Frame {
				Default item=OfficeHueSensorBatteryLevel valuecolor=[OfficeHueSensorBatteryLevel>=30="green", <30="red"]
				Default item=EveCPULoad
				Default item=EveStorageUsedPercent
				Default item=EveMemoryUsedPercent
			}
		}
	}
/*
	Frame label="Weather" {
		Text item=Weather_Temperature valuecolor=[Weather_LastUpdate=="NULL"="lightgray",Weather_LastUpdate>90="lightgray",>25="orange",>15="green",>5="orange",<=5="blue"] {
			Frame {
				Text item=Weather_Temp_Max valuecolor=[>25="orange",>15="green",>5="orange",<=5="blue"]
				Text item=Weather_Temp_Min valuecolor=[>25="orange",>15="green",>5="orange",<=5="blue"]
				Text item=Weather_LastUpdate visibility=[Weather_LastUpdate>30] valuecolor=[Weather_LastUpdate>120="orange", Weather_LastUpdate>300="red"]
			}
			Frame {
				Switch item=Weather_Chart_Period label="Chart Period" icon="chart" mappings=[0="Hour", 1="Day", 2="Week"]
				Chart item=Weather_Chart period=h refresh=600000 visibility=[Weather_Chart_Period==0, Weather_Chart_Period=="NULL"]
				Chart item=Weather_Chart period=D refresh=3600000 visibility=[Weather_Chart_Period==1]
				Chart item=Weather_Chart period=W refresh=3600000 visibility=[Weather_Chart_Period==2]
			}
		}
		Text label="Astronomical Data" icon="sun" {
			Text item=Sun_Elevation
			Text item=Sun_Azimuth
			Text item=Sunrise_Time
			Text item=Sunset_Time
			Text item=Moon_Elevation
			Text item=Moon_Azimuth
			Text item=Moon_Phase
		}
	}
	*/
}

biologist · December 26, 2018, 10:02pm

I’ve running 4x Sonoff S20 here and noticed, they loose WLAN-connection very often. So maybe have a look at the log of your router or the sonoffs.

sbeex · December 26, 2018, 10:05pm

Hello @biologist, as I said during my analysis I pushed messages myself on MQTT broker and the sonoff reacted almost directly.

It’s really related to openhab being somehow slow to write messages into MQTT -> the writing part is slow not the reading.

Thank you anyway

vzorglub · December 26, 2018, 10:07pm

When you switch a light on the sitemap, how long does it take?

sbeex · December 26, 2018, 10:09pm

@vzorglub

CDriver · December 26, 2018, 10:11pm

How many other rules do you have running frequently?

I have a similar problem with the same situation. The way I understand it is that the rules do not stay complied and cached but are flushed out. You can increase the memory allocated to java which did helped me a bit but not ideal.

Can’t find the thread now but there are lots which explain the solution. Google openhab xms heapspace and you’ll have a few examples

vzorglub · December 26, 2018, 10:11pm

Not clear sorry.

Can you post logs of when you press the button on the UI, please until the light goes on. Thanks

sbeex · December 26, 2018, 10:16pm

I don’t get your question. Sitemap is just a file there is no ui for sitemap. Are you talking about basic ui ?
if yes then we are talking about the same thing indeed:

For the logs I have no logs saying lamp is on or off after I click on the button.

sbeex · December 26, 2018, 10:21pm

That would explain why rules becomes slow indeed but not why the switch on basicui too right ?

I have moreless 1 active rule per motion sensor ~10 but we are only two person living here for now so no huge load I guess…

@CDriver on what hardware are you running openhab ? (I currently run it on a raspberrypi3 but looks like it’s a bit tight regarding RAM)

David_Graeff · December 26, 2018, 11:22pm

If you just use the mqtt binding without a rule, it should perform your ui button click instantly.
Could you maybe get rid of the rule by linking multiple items to a channel or by using profiles or any other means? Maybe even just convert to a javascript file could help.

sbeex · December 26, 2018, 11:42pm

I disabled all rules to give it a try -> it solved the latency problem.

So yes… it’s the rules that are too slow…

My rules are almost all based on “presence -> turn on/off lights”

I assume that it is only evaluated when the presence sensor state changed right ?

I use:

// when
//     Item BathroomPresence changed
// then

It’s very strange perhaps enable them one by one until it become slow to detect the slowest one ?

thank you at least I have an idea of where is the bottleneck now

CDriver · December 27, 2018, 1:39am

Im running mine on rpi 3b+. I’m not doing anything elsewhere on it though. Mqtt, sql, logging etc is all on another rpi.

sbeex · December 27, 2018, 10:23pm

I removed all my http.cfg items. I discovered that now philips hue plugin supports motion, temperature and luminosity measurement natively so no more need for a polling hack on http.

It reduced the CPU usage:

But it is still a bit slow to react to UI switches. (2 seconds)
Is it an expected range of speed or can I still improve it ?

David_Graeff · December 28, 2018, 4:21am

Internally the hue binding is also performing polling. There is a configuration value for the polling value for sensors.

sbeex · January 7, 2019, 2:32pm

Ok In fact I think I discovered what was the cause of my latencies.

Everytime I updated a rule I saved it -> and it seems openhab take a few time to sync it to the whole system. If I restart the system after having done my changes the system works fine and fast.