[SOLVED] String::format silently fails (maybe 2.5.0 M3 issue)

Tags: #<Tag:0x00007f616f32fa50> #<Tag:0x00007f616f32f938> #<Tag:0x00007f616f32f730>

I have recently upgraded to openHAB 2.5.0 Milestone 3 from M2. I am not really sure whether this has something to do with that upgrade but my previously working code has an issue at a certain point. I have found out that a String::format statement silently fails. Here is my setup:

Items

Number Taupunkt_Differenz "Taupunktdifferenz Δtd [%.1f °C]" <humidity>

Taupunkt_Differenz is a calculated item out of 2 doubleValues.

myrule.rules

rule "My rule"
when
	Item Taupunkt_Differenz changed
then
	val Number taupunkt_delta = Taupunkt_Differenz.state as DecimalType
	val td=1.2345
	logInfo("myrule.rules", "td=" + td + " | taupunkt_delta=" + taupunkt_delta)
	var String test1 = String::format("%.1f °C", td)
	logInfo("myrule.rules", "test1=" + test1)
	var String test2 = String::format("%.1f °C", taupunkt_delta)
	logInfo("myrule.rules", "test2=" + test2) // this line won't be reached!
	// ...
	// (more code)
	// ...
end

The complete log output is

2019-09-15 10:49:00.018 [INFO ] [me.model.script.myrule.rules] - td=1.2345 | taupunkt_delta=0.8502743895760965
2019-09-15 10:49:00.025 [INFO ] [me.model.script.myrule.rules] - test1=1,2 °C

and that’s it. The last logInfo is missing. So my impression is that the second String::format statement fails and the rule is exited without any error message because the following code is not executed.

I am quite sure that this code worked before. Does anybody have an idea what is going on here?

Did you add another test logInfo:

	var String test1 = String::format("%.1f °C", td)
	logInfo("myrule.rules", "test1=" + test1)
	var String test2 = String::format("%.1f °C", taupunkt_delta)
        logInfo("TEST", "TEST")
	logInfo("myrule.rules", "test2=" + test2) // this line won't be reached!

Is that one logged?

1 Like

No, unfortunately not.

What about this:

	//var String test2 = String::format("%.1f °C", taupunkt_delta)
        var String test2 = "TEST"
        logInfo("TEST", test2)

This one does work. Output as expected.

Ok so now we are sure it’s that line causing problems
Delete it completely
Save the file
Type it in again (Not copy paste) there maybe some hidden stuff in it (Weird I know, it happens…)

I followed your directions but still no change. There must be something wrong with the float formatting because this here

logInfo(logName, "td=" + td + " | taupunkt_delta=" + taupunkt_delta)
var String test1 = String::format("%.1f °C", td)
logInfo(logName, "test1=" + test1)
var String test2 = String::format("%s", taupunkt_delta)
logInfo("TEST", "test2=" + test2)
var String test3 = String::format("%s", taupunkt_delta)
test3 = String::format("%.1f", taupunkt_delta)
logInfo("TEST", "test3=" + test3)

produces the following output (last logInfo not executed):

2019-09-15 12:34:30.009 [INFO ] [me.model.script.myrules.rules] - td=1.2345 | taupunkt_delta=0.2726788936991973
2019-09-15 12:34:30.013 [INFO ] [me.model.script.myrules.rules] - test1=1,2 °C
2019-09-15 12:34:30.018 [INFO ] [.eclipse.smarthome.model.script.TEST] - test2=0.2726788936991973

Very strange.

And if you remove the third one, does the second one still appear?

Possible clue about language formatting (decimal separator)

Yes.

Yes, that could be an issue. But in a different rule something like this

Klima_Keller.sendCommand(String::format("T=%.1f °C | φ=%.0f%% | td=%.1f °C", t, h, d))
logMessage += String::format("=%.1f °C (T=%.1f °C, φ=%.0f %%)", d, t, h)

works without a flaw.

What happens if you use instead

val taupunkt_delta = Taupunkt_Differenz.state as Number

Rules are bit loose about typing. Either “should” work of course.

This makes no difference, too. The String::format part still fails. I wonder why there are no error messages in the logs. It is just as if the rule will be left at this very point.

Very odd

val taupunkt_delta = Taupunkt_Differenz.state as Number
val td=1.2345

should both result in Number objects, I think?
Try
val Number td=1.2345

Don’t know, all very odd, trying to home in on what breaks it.

Yes, I think so, too.

Still no difference…

I also tried this here:

logInfo("TEST", "Taupunkt_Differenz=" + Taupunkt_Differenz)
logInfo("TEST", "taupunkt_delta=" + taupunkt_delta)
var Number td=1.2345
logInfo("TEST", "td=" + td + " | taupunkt_delta=" + taupunkt_delta)
var String test1 = String::format("%.1f °C", td)
logInfo("TEST", "test1=" + test1)
var String test2 = String::format("%s", taupunkt_delta)
logInfo("TEST", "test2=" + test2)
td = taupunkt_delta
logInfo("TEST", "before test3")
var String test3 = String::format("%.1f °C", td)
logInfo("TEST", "test3=" + test3)
var String test4 = String::format("%.1f °C", taupunkt_delta)
logInfo("TEST", "test4=" + test4)

The log now ends with test #3:

2019-09-15 13:40:42.278 [INFO ] [.eclipse.smarthome.model.script.TEST] - Taupunkt_Differenz=Taupunkt_Differenz (Type=NumberItem, State=0.7088823820515522, Label=Taupunktdifferenz Δtd, Category=humidity, Groups=[Weather, Temperature])
2019-09-15 13:40:42.293 [INFO ] [.eclipse.smarthome.model.script.TEST] - taupunkt_delta=0.7088823820515522
2019-09-15 13:40:42.303 [INFO ] [.eclipse.smarthome.model.script.TEST] - td=1.2345 | taupunkt_delta=0.7088823820515522
2019-09-15 13:40:42.311 [INFO ] [.eclipse.smarthome.model.script.TEST] - test1=1,2 °C
2019-09-15 13:40:42.319 [INFO ] [.eclipse.smarthome.model.script.TEST] - test2=0.7088823820515522
2019-09-15 13:40:42.326 [INFO ] [.eclipse.smarthome.model.script.TEST] - before test3

There must be something wrong with the taupunkt_deltavariable which the format statement does not like.

Longshot; try
td = taupunkt_delta + 1

1 Like

Yes! For whatever reason, this did the trick! Now this approach works:

val Number taupunkt_delta = Taupunkt_Differenz.state as DecimalType + 0 // needed to avoid non-working String::format
var String test = String::format("%.1f °C", taupunkt_delta)
logInfo("myrule.rules", "test=" + test) // now it works!

Many thanks to @rossko57 & @vzorglub for helping me solve it!

Nevertheless I wonder why this happens because it worked before and it is still working in other rules…

Now that’s weird behaviour…

I was worrying about the leading zero maybe followed by comma actually, amazed it works with + 0
Something to do with hidden baggage here. QuantityType issues shouldn’t be coming into play with a plain Number type Item, but it has that feel.

I had a play with this in OH2.4
The good news is an error message appears -
f != org.eclipse.smarthome.core.library.types.DecimalType

As we all probably expected, it’s to do with Java formatter not liking object type passed in.

But first, why did you not get the error message? Something odd about your install, like logging problems or locale, or is it a general OH2.5 issue?
Need an OH2.5 M3 user to try the following out please.

Okay, so a demo rule to show the issue

rule "format state"
when
   Item nm_test_temp changed
then
      // Item nm_test_state is defined: Number nm_test_temp "temp [%.1f °C]"
   val teststateA = (nm_test_temp.state as DecimalType).floatValue
   val teststateB = nm_test_temp.state as DecimalType
   logInfo("myrule.rules", "teststateA=" + teststateA.getClass)
   logInfo("myrule.rules", "teststateB=" + teststateB.getClass)
   var String test2 = String::format("%.1f °C", teststateA)
   logInfo("myrule.rules", "A formatted=" + test2)
   var String test3 = String::format("%.1f °C", teststateB)
   logInfo("myrule.rules", "B formatted=" + test3) // this line won't be reached!
end

openhab.log

2019-09-16 00:33:48.085 [INFO ] [.smarthome.model.script.myrule.rules] - teststateA=class java.lang.Float
2019-09-16 00:33:48.086 [INFO ] [.smarthome.model.script.myrule.rules] - teststateB=class org.eclipse.smarthome.core.library.types.DecimalType
2019-09-16 00:33:48.088 [INFO ] [.smarthome.model.script.myrule.rules] - A formatted=15.5 °C
2019-09-16 00:33:48.090 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'format state': f != org.eclipse.smarthome.core.library.types.DecimalType

So, a java float type (A) satisfies the java String formatter
An openHAB/Eclipse DecimalType does not.

I think the error message is a bit backwards ; at first it seems like it is expecting a org.eclipse.smarthome.core.library.types.DecimalType, but I think the closer meaning is that “f” (as in %.1f) is complaining that it cannot work with DecimalType.

Remembering that String::format is “raw java” and not openHAB-ified, this is perhaps not that surprising after all.

1 Like