[SOLVED] Logging from rules prints format codes, not formatted values

Setup, Configuration and Use Scripts & Rules
, ,
1
  • Platform information:
    • Hardware: _Raspberry Pi 2
    • OS: Raspbian Stretch
    • Java Runtime Environment:
      openjdk version “1.8.0_152”
      OpenJDK Runtime Environment (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 1.8.0_152-b76)
      OpenJDK Client VM (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 25.152-b76, mixed mode, Evaluation)
    • openHAB 2.2:
  • Issue of the topic: LogInfo String Formatting not working
  • Please post configurations (if applicable):
    • Items configuration related to the issue
    • Sitemap configuration related to the issue
    • Rules code related to the issue

** logInfo prints the format codes, not the formatted variable values **

rule "Family Room Temperature Check"
when
    Item Sensor_FF_FR_Temperature changed
then
    if (Sensor_FF_FR_Temperature.state != null && Sensor_FF_FR_Temperature.state != NULL) {
        if (fr_temp_lastvalue != null && fr_temp_lastvalue != NULL) {
             logInfo("DefaultRules",
                     "Temperature changed from %1$.1f°C to %1$.1f°C",
                     fr_temp_lastvalue,
                     Sensor_FF_FR_Temperature.state
                    )
             if (19 <= fr_temp_lastvalue && fr_temp_lastvalue <= 22) {
                 if (Sensor_FF_FR_Temperature.state < 19) {
                     loginfo("DefaultRules", "Alarm: Family Room temperature too low")
                     sendMail("chris@mydomain.net", "Temperature Alarm",
                              "Temperature in Living Room is below threshold")
                 }
                 if (22 < Sensor_FF_FR_Temperature.state) {
                     loginfo("DefaultRules", "Alarm: Family Room temperature too high")
                 }
             }
        }
    fr_temp_lastvalue = Sensor_FF_FR_Temperature.state
    }
end
  • Services configuration related to the issue
  • If logs where generated please post these here using code fences:
2020-01-19 09:34:58.943 [INFO ] [.smarthome.model.script.DefaultRules] - Temperature changed from %1$.1f°C to %1$.1f°C
2020-01-19 09:35:01.007 [INFO ] [.smarthome.model.script.DefaultRules] - FR Luminance now [150], was [146]
2020-01-19 09:36:00.500 [INFO ] [.smarthome.model.script.DefaultRules] - Temperature changed from %1$.1f°C to %1$.1f°C

I lifted the format code from the example in the openhab 2.2 documentation (2nd example, last line). I know I can always convert the variable to a string but I prefer the style of this method (although I like Python 3.6+ formatting the most).

So it looks like it supposed to work in 2.2.

Thanks in advance,
Chris

NB: The temperature range is pretty narrow so I can test the rule based on my thermostat setback. The range will be widened for actual use, to protect the house against a failed or runaway furnace when on vacation.

1 Like
2

That documentation seems to be incorrect. How does this work for you?

logInfo("DefaultRules",
                     "Temperature changed from {}°C to {}°C",
                     fr_temp_lastvalue,
                     Sensor_FF_FR_Temperature.state
                    )

Or this…

logInfo("DefaultRules",
                     "Temperature changed from {}°C to {}°C",
                     fr_temp_lastvalue.format("%.1f"),
                     Sensor_FF_FR_Temperature.state.format("%.1f")
                    )
1 Like
3

Thank you Scott. The numbers come out with about 15 decimal places so I was just looking for some tidiness by keeping it to 1 decimal place. I will use your second example as the output is what I wanted, I was just reluctant to go that direction because it seems a bit primitive.

Thanks for confirming my suspicions about the documentation.

Chris

2 Likes
4

OK I’ve had a chance to try these things and it got a lot stranger. This is what I saw

Temperature changed from 21.2777777777777777777777777777778 °C°C to 21.1666666666666666666666666666667 °C°C

So I realize now that I’m getting a formatted string from the sensor, including the °C. I’d be impressed if the temperature measurement accuracy matched its precision, but I’m not convinced it’s even within a full degree.I suspect that the native scale is Fahrenheit, so I’m seeing the results of the divide by 9 inherent in F to C conversion.

Anyway, formatting isn’t going to help. I suppose I could parse it and then format it. Maybe I’ll just go with Fahrenheit. :slight_smile:

Chris

5

What sensor are you using? Some have selectable units.

6

Aeotec Multisensor 6. It will do Fahrenheit. I live in Canada, though, so we’ve been using Celsius since '75.

7

I remember that change well when I lived in Canada.
Look for Advanced configuration options. It appears to me that most firmware versions used part of parameter 41 to set the temperature threshold unit. What firmware version is your sensor?

1 Like
8

Look in your events.log to see what the Item “raw” state is being updated to.
Look at your Item definition, is it a String or Number:Temperature type?

9

From what I read in the docs 41 will is a temperature threshold which will trigger a “report”, which I think is for battery operation (though I’m not by any means certain). I’m using USB power it reports every minute. I was just trying to figure out how to use parameters that aren’t channels earlier today but have some more testing to do.

I don’t know what firmware version I have as I don’t know how to determine that.

This is my item definition:

Number:Temperature Sensor_FF_FR_Temperature "Family Room [%.1f %unit%]" <temperature> { channel="zwave:device:1f16f561:node8:sensor_temperature" }

Here’s an event that was logged

2020-01-19 20:18:58.370 [vent.ItemStateChangedEvent] - Sensor_FF_FR_Temperature changed from 20.6666666666666666666666666666667 °C to 20.7777777777777777777777777777778 °C
10

Okay, it is a Quantity Type, which carries units with it as part and parcel of the value. The binding supplies a unit when it updates the Item.
I’d agree the incoming raw data is probably °F, the binding is peeking at the Item label for a clue what units you would prefer, finds %unit% (don’t care), looks at your locale for preferred units, and so converts to °C

In rules or display, you get to choose what (appropriate) units to deal in, and auto conversion will be applied.
For example, your label state formatter is now [%.1f %unit%] so that has the UI display one decimal place and the current units. You might use [%.0f °F] instead if you wanted a round number in Fahrenheit, regardless of how it is stored in the state.

Obviously in your rule, you’d use much the same kind of thing for the .format()

11

I usually like to use HABmin. Configuration → Things → [sensor] → Attributes (at the bottom) Here is a different sensor with firmware 1.3.
image

In PaperUI, Configuration → Things click on the sensor. Click Show Properties. All the way at the bottom is zwave_version.

image
image681×565 25.5 KB

12

Your rule led me to think that you were not using UoM. To do the logging you want, you’ll need to do something like this…

logInfo("DefaultRules",
                     "Temperature changed from {} {} to {} {}",
                     fr_temp_lastvalue.format("%.1f"),
                     fr_temp_lastvalue.unit
                     Sensor_FF_FR_Temperature.state.format("%.1f"),
                     (Sensor_FF_FR_Temperature.state as QuantityType<Temperature>).unit,
                    )

My last example had some issues that I’ve cleaned up too.

1 Like
13

Thanks to all of you for your help. Combining it all, I have pieced together a solution. FYI the firmware is V1.6 and the sensor reports in increments of 0.2 degrees Fahrenheit.

I changed the Temperature sensor from Number:Temperature to Number. This stopped the conversion to Celsius, but more important stopped the formatting of the number as a string. So now I can do math on it.

I created an additional item to hold the Celsius value which wasn’t bound to anything.

Then added a rule

rule "Family Room Temperature Change"
when
    Item Sensor_FF_FR_Temperature changed
then
    if (Sensor_FF_FR_Temperature.state != null) {
        Sensor_FF_FR_Celsius.postUpdate((Sensor_FF_FR_Temperature.state as Number - 32) * 5/9)
        logInfo("DefaultRules", "FR Temperature {} F, {} C", Sensor_FF_FR_Temperature.state, Sensor_FF_FR_Celsius.state)
    }
end

I thought it might be a problem as the log showed this the first time the rule fired.

FR Temperature 66 F, NULL C

But the next time it was

FR Temperature 65.8 F, 18.77777778 C

Then finally modified the initial rule to use the Sensor_FF_FR_Celsius value instead of the original value. It clearly fired both times as it showed the old value and new value.

Temperature changed from 18.88888889 to 18.77777778

So maybe there’s a minuscule timing window open in the postUpdate operation that results in the following line to get the old state sometimes.

The problem with getting the values as string was also that the comparison operators weren’t working, so this was necessary for more than just logging.

I’m still having trouble formatting the numbers though.

Sensor_FF_FR_Celsius.state.format("%.1f") resulted in a complaint about the format method not available for type Number.

14

OK We do not show that version has having the units setting. Out database entry is here.

https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/73

1 Like
15

That is because you removed UoM. I suggest you put the Items back the way they were and learn how to use QuantityTypes. They are very powerful and greatly simplify conversions. Using QuantityTypes and Celcius, your comparisons would look like…

             if (19|°C <= fr_temp_lastvalue && fr_temp_lastvalue <= 22|°C) {
                 if (Sensor_FF_FR_Temperature.state < 19|°C) {
...
                 if (22|°C < Sensor_FF_FR_Temperature.state) {
2 Likes
16

fr_temp_lastvalue.format("$.1f") gives the same error with the format method. It won’t let me give it a type of Number:Temperature, so should I make it an item to get around it, or is there some more elegant way to do it?

Rule 'Family Room Temperature Check': 'format' is not a member of 'java.lang.Number'; line 136, column 22, length 32
17

You’ve thrown information away, for a small benefit in writing rules. It would be better to deal with the data as supplied.

Yes. By design, it is asynchronous.
When you postUpdate, it puts your request on the openHAB event bus - for the benefit of any bindings, rules, UIs etc. that are interested. The actual state update is updated shortly but not instantly.
Your rule does not stop and wait for all those processes to complete.

myItem.postUpdate("X")
logInfo("test", "almost certainly get the old value here = " + myItem.state.toString")

You’ve no need ever to do that - your rule knows what X is, it just posted it.

If you really need to do something after the postUpdate has been actioned, this is what the rule triggers are for. Fire another rule from Item xx updated
It takes a bit of getting used to this asynchronous event-driven stuff.

18

Oh my… I thought this was an Item. There is no definition for it in the OP. So, this is a variavle to hold the last value of the Item? There is no need for that, since it is stored for you. I should have looked deeper into your rule from the beginning, rather than just providing the answer to the question you were asking. Here is a complete rewrite of your rule. Ask if you have questions!

rule "Family Room Temperature Check"
when
    Item Sensor_FF_FR_Temperature changed
then
    if (newState != NULL && previousState != NULL) {
        logInfo("DefaultRules",
                "Temperature changed from {} {} to {} {}",
                previousState.format("%.0f"),
                previousState.unit,
                newState.format("%.0f"),
                newState.unit
            )
        if (19|°C <= previousState && previousState <= 22|°C) {
            if (newState < 19|°C) {
                loginfo("DefaultRules", "Alarm: Family Room temperature too low")
                sendMail("chris@mydomain.net", "Temperature Alarm",
                        "Temperature in Living Room is below threshold")
            } else if (newState > 22|°C) {
                loginfo("DefaultRules", "Alarm: Family Room temperature too high")
            }
        }
    }
end
19

Well that looks nice and elegant, although it requires V2.5. So I just upgraded and now have some other debugging to do!

Thanks again for your help.

1 Like
20

Oops… sorry about that. The newState variable is new, but previousState was probably around in 2.2. It’s a good time to upgrade though… OH 3.0 will be a while.

1 Like