OH1 to homematic - commands are sent only sometimes!

Hello,

What I want to do is quite simple.
Opening the window shall shut down the heating,
Closing the window shall turn on the heating.

The windows contact is realized via KNX.
The heating is controlled via a homematic thermostat.

The issue is that if I open (or close) the window then the necessary commands to shut down (or to turn on) the heating are send only sometimes. For closing the window it is the same issue.

The homematic item definition looks like this

Group gEG_Buero_H	"Heizung"	<heating>	(gEG_Buero)
Number Heating_EG_Buero_GetTemp 			"EG Büro Ist-Temperature [%.1f °C]"		<temperature>	(gHomematic, gEG_Buero_H, gTemperature)	{homematic="address=LEQ0846688, channel=4, parameter=ACTUAL_TEMPERATURE" }
Number Heating_EG_Buero_SetTemp 			"EG Büro Soll-Temperature [%.1f °C]"	<temperature>	(gHomematic, gEG_Buero_H, gTempSet)		{homematic="address=LEQ0846688, channel=4, parameter=SET_TEMPERATURE" }
Number Heating_EG_Buero_Valve 				"EG Büro Ventil [%d %%]"				<heating>		(gHomematic, gEG_Buero_H)				{homematic="address=LEQ0846688, channel=4, parameter=VALVE_STATE" }
Number Heating_EG_Buero_Battery 			"EG Büro Batterie [%.1f V]"				<battery>		(gHomematic, gEG_Buero_H, gBattery)		{homematic="address=LEQ0846688, channel=4, parameter=BATTERY_STATE" }
Number Heating_EG_Buero_Error	 			"EG Büro Fehler [MAP(hmError.map):%d]"	<smiley>		(gHomematic, gEG_Buero_H, gError)		{homematic="address=LEQ0846688, channel=4, parameter=FAULT_REPORTING" }
Number Heating_EG_Buero_GetMode 			"EG Büro Mode [MAP(hmMode.map):%d]"		<heating> 		(gHomematic, gEG_Buero_H, gMode)		{homematic="address=LEQ0846688, channel=4, parameter=CONTROL_MODE" }
Switch Heating_EG_Buero_SetModeAuto 		"EG Büro Auto Mode"										(gHomematic, gEG_Buero_H)				{homematic="address=LEQ0846688, channel=4, parameter=AUTO_MODE" }
Number Heating_EG_Buero_SetModeManual 		"EG Büro Manuel Mode"									(gHomematic, gEG_Buero_H)				{homematic="address=LEQ0846688, channel=4, parameter=MANU_MODE" }

the definition of the KNX items (windows)

Contact Window_EG_Buero_FL 	"EG Bürofenster links [MAP(de.map):%s]"		(gEG_Buero, gWindows, gKNX)		{ knx="<5/2/9" }
Contact Window_EG_Buero_FR	"EG Bürofenster rechts [MAP(de.map):%s]"	(gEG_Buero, gWindows, gKNX)		{ knx="<5/2/10" }

Here is the rule

rule "EG Büro If window open then stop heating"
when
	Item Window_EG_Buero_FL changed or
	Item Window_EG_Buero_FR changed
then
	logInfo("INFO","EG_Buero Windows changed")
	// first check if central-heating boiler is on (only in winter / heating period)
	if (HeatingON.state == ON) {
		if ((Window_EG_Buero_FL.state == OPEN) || (Window_EG_Buero_FR.state == OPEN)) { 
			logInfo("INFO","EG_Buero Windows open")
			// shut down heating
			Heating_EG_Buero_SetModeManual.sendCommand(4.5)
			// to make UI consistent - set AUTO mode to off
			Heating_EG_Buero_SetModeAuto.postUpdate(OFF)
		} else {
			logInfo("INFO","EG_Buero Windows closed")
			// turn heating on
			Heating_EG_Buero_SetModeAuto.sendCommand(ON)
		}
	} else {
		logInfo("INFO","EG_Buero Windows OFF")
		// just for security - turn heation off
		Heating_EG_Buero_SetModeManual.sendCommand(4.5)
		// to make UI consistent - set AUTO mode to off
		Heating_EG_Buero_SetModeAuto.postUpdate(OFF)
	}
end

and here is what I see in openHAB.log, what is exactly what I expect to see

11:26:37.506 INFO  org.openhab.model.script.INFO[:53]- EG_Buero Windows changed
11:26:39.560 INFO  org.openhab.model.script.INFO[:53]- EG_Buero Windows open
11:28:12.369 INFO  org.openhab.model.script.INFO[:53]- EG_Buero Windows changed
11:28:12.438 INFO  org.openhab.model.script.INFO[:53]- EG_Buero Windows closed

but in event.log I see only this

2017-09-29 11:26:40 - Window_EG_Buero_FL state updated to OPEN
2017-09-29 11:26:40 - Heating_EG_Buero_SetModeManual received command 4.5
2017-09-29 11:26:44 - Heating_EG_Buero_SetModeAuto state updated to OFF
2017-09-29 11:26:51 - Heating_EG_Buero_GetMode state updated to 0
2017-09-29 11:26:51 - Heating_EG_Buero_Error state updated to 0
2017-09-29 11:26:51 - Heating_EG_Buero_Battery state updated to 2.90
2017-09-29 11:26:51 - Heating_EG_Buero_Valve state updated to 0
2017-09-29 11:26:51 - Heating_EG_Buero_GetTemp state updated to 24.60
2017-09-29 11:26:51 - Heating_EG_Buero_SetTemp state updated to 21.00
2017-09-29 11:29:50 - Heating_EG_Buero_GetMode state updated to 0
2017-09-29 11:29:50 - Heating_EG_Buero_Error state updated to 0
2017-09-29 11:29:50 - Heating_EG_Buero_Battery state updated to 2.90
2017-09-29 11:29:50 - Heating_EG_Buero_Valve state updated to 0
2017-09-29 11:29:50 - Heating_EG_Buero_GetTemp state updated to 24.60
2017-09-29 11:29:50 - Heating_EG_Buero_SetTemp state updated to 21.00
2017-09-29 11:32:34 - Heating_EG_Buero_GetMode state updated to 0
2017-09-29 11:32:34 - Heating_EG_Buero_Error state updated to 0
2017-09-29 11:32:34 - Heating_EG_Buero_Battery state updated to 2.90
2017-09-29 11:32:34 - Heating_EG_Buero_Valve state updated to 0
2017-09-29 11:32:34 - Heating_EG_Buero_GetTemp state updated to 24.50
2017-09-29 11:32:34 - Heating_EG_Buero_SetTemp state updated to 21.00

here the opening event of the window is reported correctly
but not the closing event (should be at 2017-09-29 11:28:13 or something like this - compare with openHAB.log).
Why?

How shall I do further debugging?
Of course I already checked with the homematic WebUI whether I am able to control the heating thermostat and it works fine.
Additionally I get a lot of sensor data from homematic sensors, so basically the communication with homematic works.
Further I do not have any warning about bad communication in the homematic WebUI.

I run OH1.8.3 on a QNAP TP-419P with latest firmware 4.3.3.0299 Build 20170901 connected with Ethernet to a homematic CCU2 (latest firmware 2.29.22).

Any help appreciated.
Axel

I don’t understand how the rule is triggering to get your “correct” openhab.log but it doesn’t show up in events.log. If it doesn’t appear in events.log that would mean that it never hit the event bus which means that there was no event to trigger the rule. I don’t understand how this is possible.

Unfortunately, you are running a version of OH that is three versions behind and I’m not sure how many people are left who have recent enough experience to help out with this much. And if indeed your rule is triggering but the event is not appearing in the events log that is a problem that lies in the core of OH which, even if we were to identify the problem, will never be fixed.

OK, I added to the initial posting the definition of the KNX windows items which trigger successfully the rule (as you can see by the INFO entry in the openHAB.log).

Second, I would love to switch to OH2 but there is no usable installation for QNAP systems.
There exists one but this does not survive reboot as you need to reinstalled OH2 to get it run again (no idea why?) therefore I am still on OH1.8.3 which is the latest working one for my system.

Kind regards,
Axel