[avmfritz] DECT Thermostat Handler crashes after being changed by external call (calendar event in my case) causing the state to be lost

[Schm1tz1]

After migration to OH3 I am experiencing a NULL poniter exception in ThingHandler.handleCommand() after the set value is changed by an external rule/event (icalendar in my case). Using The UI changing the set value for the DECT thermostat works without any issues.

Part of the log showing the behavior:
2021-01-10 16:45:43.239 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Thermostat_OG_Bad' received command 21
2021-01-10 16:45:43.260 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Thermostat_OG_Bad' predicted to become 21
2021-01-10 16:45:43.282 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Thermostat_OG_Bad' changed from 20.0 to 21
2021-01-10 16:45:43.305 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.avmfritz.internal.handler.AVMFritzHeatingDeviceHandler@cc08da': null
2021-01-10 16:45:43.905 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Thermostat_OG_Bad' changed from 21 to 20.0

Full Stacktrace:
[ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.avmfritz.internal.handler.AVMFritzHeatingDeviceHandler@cc08da': null
java.lang.NullPointerException: null
at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseThingHandler.handleCommand(AVMFritzBaseThingHandler.java:348) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:154) [bundleFile:?]
at org.openhab.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
at com.sun.proxy.$Proxy299.handleCommand(Unknown Source) [?:?]
at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:80) [bundleFile:?]
at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:154) [bundleFile:?]
at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:834) [?:?]

Expected Behavior

New set point (21°C in my case) should be set until changed manually or by an external trigger.

Current Behavior

Current state of the set point is lost and previous state is restored .

Possible Solution

Not yet - have to track the NULL pointer...

Steps to Reproduce (for Bugs)

1. In Generate a calendar event to set the termostat's set value: "BEGIN:Thermostat_OG_Bad:21\nEND:Thermostat_OG_Bad:16"
2. Wait for the calendar event to trigger and check the logs.

Context

see initial description. Heating-Set-Points based on iCalendar.

Your Environment

• Version used: openHAB 3.0.0, AVM FRITZ!Box Binding 3.0.0,iCalendar Binding 3.0.0
• FRITZ!Box 6590 Cable w. FritzOS 07.20, Comet DECT Thermostats (FW 03.54)
• Operating System and version (desktop or mobile, Windows 10, Raspbian Buster, ...): openHABianPi 4.19.66-v7+

[cweitkamp]

Thanks for reporting this issue. Looks similar to this community post. Do you send a command using the temperature unit (e.g. 21 °C) or a plain number?

[Schm1tz1]

That was fast- thanks for the reply. I am sending without °C, this might be the cause for this - I will check.
BEGIN:Thermostat_OG_Bad:21
END:Thermostat_OG_Bad:16

[Schm1tz1]

Indeed this fixed it:
BEGIN:Thermostat_OG_Bad:21 °C
END:Thermostat_OG_Bad:16 °C

A bit weird though as there seems to be a breaking API-change since 2.5. A fall-back to a default unit together with a warning or error message should be included IMHO. Thanks for the help - nevertheless I will have a look into the code.

[cweitkamp]

I did a quick analysis. The root cause is the following constellation of implementations in both bindings (avmfritz and icalendar).

openhab-addons/bundles/org.openhab.binding.icalendar/src/main/java/org/openhab/binding/icalendar/internal/logic/CommandTag.java

Lines 48 to 50 in b6eea71

	private static final List<Class<? extends Command>> otherCommandTypes = Arrays.asList(QuantityType.class,
	OnOffType.class, OpenClosedType.class, UpDownType.class, HSBType.class, PlayPauseType.class,
	RewindFastforwardType.class, StringType.class);

icalendar binding: The given command line in the calendar events will be parsed according to the above ordered list. Meaning QuantityType will be checked first. This seems to succeed but without a proper unit (One will be used instead, if you do not define something). I am wondering why DecimalType is missing in this list. We have to ask @daMihe for the reason.

openhab-addons/bundles/org.openhab.binding.avmfritz/src/main/java/org/openhab/binding/avmfritz/internal/handler/AVMFritzBaseThingHandler.java

Lines 369 to 372 in b6eea71

	} else if (command instanceof QuantityType) {
	temperature = normalizeCelsius(
	((QuantityType<Temperature>) command).toUnit(SIUnits.CELSIUS).toBigDecimal());
	} else if (command instanceof IncreaseDecreaseType) {

avmfritz binding: We now receive a QuantityType command in the avmfritz handler and try to convert it to Celsius. The method toUnit(Unit<?>) will return a null value if the given value cannot be parsed to the target unit. This is not handled correctly. I submitted a fix for it in #9778.