Logging with format-strings section is incorrect

[punkadiddle]

There is an example in the docs that recommends to log using format strings: logDebug("heating-control.rules", "Bedroom: Temperature: %1$.1f°C, Mode %2$s", Bedroom_Temp.state, Bedroom_Heater_Mode.state)

This is not working; it's seems to be out of sync with the implementation. All the format characters are printed in the log. See also https://community.openhab.org/t/formatting-of-log-entries/36689

What is working is using brackets as placeholders {} to print arguments in order or to wrap the whole String/Arguments in a String::format(...) call. The latter is not typical for logging as it produces the string regardless of the log level.

[Confectrician]

There is an example in the docs

Can you remember on which docs page this is explained? I would guess its somewhere in the rules article, but maybe you know it and can fasten my search. :)

[mi42]

Sorry, it's on the following page in the section about loggin in rules: https://www.openhab.org/docs/administration/logging.html#create-log-entries-in-rules

[Confectrician]

Correct usage: https://community.openhab.org/t/formatting-of-log-entries/36689/4?u=confectrician or https://community.openhab.org/t/formatting-of-log-entries/36689/6?u=confectrician

[Confectrician]

I think this doesn't work for jsr223 scripting. But that's a general problem we have to address in the future.

[Confectrician]

I have tested it now and i am not sure about the second version. I think the String::format option is the better one, according its ability to give a format.

[punkadiddle]

Any idea where the {} bracket formatting comes from? Maybe it can do more than just empty brackets.

To answer that:

Here's the implementation (thanks to Google): https://github.com/openhab/openhab-core/blob/master/bundles/org.openhab.core.model.script/src/org/eclipse/smarthome/model/script/actions/LogAction.java

@param format the Log-Statement which can contain placeholders '<code>{}</code>'

And some documentation on it: https://www.slf4j.org/faq.html#logging_performance

SLF4J only cares about the formatting anchor, that is the '{' character immediately followed by '}'.

My guess: just offering the anchor without format options serves robustness. (I have seen my own "pretty" String::format based logging messages fail more than once.) So there's

• a robust, but technical way which serves the idea of getting stuff out easily as is -- even in edge-cases (productive logging)
• a human-friendly way which looks nicer (which might be what hobbiests want in their rules) but is harder to write and not as fail-safe (try applying number-formatting to null)

[Confectrician]

I made some tests too yesterday. And i would change my mind and say String::format is harder too use. I have tested units of measurement items several times and didn't get it to work properly.

We should think about the easiest way to use and maybe add an advanced way of usage.

[5iver]

Parameterized logging definitely should be the recommended method for use in the rules DSL.

I think this doesn't work for jsr223 scripting.

For future reference, you can use LogAction, or SL4FJ directly, with parameterized logging in JSR223...

# Jython
from org.eclipse.smarthome.model.script.actions.LogAction import logInfo
test = 55555
logInfo("Rules", "This is a test [{}]", test)

from org.slf4j import LoggerFactory
LoggerFactory.getLogger("jsr223.jython").info("This is another test [{}]", test)

// Javascript
'use strict';
var logInfo = Java.type("org.eclipse.smarthome.model.script.actions.LogAction").logInfo;
var test = 55555;
logInfo("Rules", "This is a test [{}]", test);

// Groovy
import org.eclipse.smarthome.model.script.actions.LogAction
def logInfo = LogAction.&logInfo
test = 55555
logInfo("Rules", "This is a test [{}]", test)

https://community.openhab.org/t/how-to-setup-jython/53049/149?u=5iver

[wborn]

This seems to have already been fixed by https://github.com/openhab/openhab-docs/pull/1144.

[Confectrician]

Thanks for the catch. 🙂