Debug logging in rules

rules
debuglogging
Tags: #<Tag:0x00007f1e6e2e9c60> #<Tag:0x00007f1e6e2e9800>
(Joseph F. Karnicky) #1

This message continues from a previous forum thread:
https://community.openhab.org/t/executecommandline-on-a-windows-machine/38648/16
I thought that because of thread drift I should start a new topic. Good idea? Bad idea?

I am still trying (unsuccessfully) to log some debug information.
I am working from this documentation page:
https://docs.openhab.org/v2.1/administration/logging.html
I executed the following console commands

log:set DEBUG org.openhab.binding.exec
log:set DEBUG org.eclipse.smarthome.script.logtest.rules

and then loaded the file “logtest.rules” which contains a single rule:

//Turn on the wemo mini switch when openhab2 launches
rule "first rule"

when
	System started
then
	val input = executeCommandLine("C:\\head@@-n@@1@@C:\\openhabinput.txt", 5000)//no complaints 
	logDebug("logtest", "this is a log entry of type debug")
	Switch1_state.sendCommand(ON)
end

The rule is triggering (as evidenced by the switch turning on) but I don’t see any logging information either in the console nor in the log files.

  1. Are the above console commands correct?
  2. I used the name of the .rules file as the 1st argument to logDebug. Is this correct?
  3. am I doing something else wrong?

Thanks in advance,
Joe

0 Likes

executeCommandLine on a Windows machine
(namraccr) #2

Which version of OH2 are you running?

This rule works for me in 2.1:

rule testLogging
when
  System started
then
  logWarn("myLog", "Chim Chimney Chim Chimney Chim Chim Cheree")
end

And produces this output:

22:16:16.388 [WARN ] [eclipse.smarthome.model.script.myLog] - Chim Chimney Chim Chimney Chim Chim Cheree
0 Likes

(namraccr) #3

Also, to directly answer your questions:

  1. The karaf commands look fine. The best way to check is to run them and then look at the log levels with log:list
  2. Shouldn’t matter. the 1st argument is an arbitrary string
  3. Not that I see
0 Likes

(Joseph F. Karnicky) #4

Thanks very much for the reply. I’m making progress.
It turns out that if I use logWarn as in your example I DO see logging. However, if I use logDebug I DON’T see logging. I am now experimenting with what other logging levels do or don’t act as I expect. (I am using openhab 2.1)
In the meantime,

  1. do you set your log level in the console or do you have a configuration file? (Maybe that makes a difference?)

  2. would it be possible for you to change your log level to DEBUG/logDebug and let me know what happens?

  3. some place in the documentation I remember seeing the syntax for using the Java format style of substituting variable values into the output string but I can’t find it anymore. Have you seen that or do you have an example in any of your rules?

Best regards,
Joe

0 Likes

(namraccr) #5

While writing the response below, I think I found the problem. You said you used this command:

log:set DEBUG org.eclipse.smarthome.script.logtest.rules

If that’s not a typo, I think it’s wrong. Should be this instead:

log:set DEBUG org.eclipse.smarthome.model.script.logtest.rules
or just
log:set DEBUG org.eclipse.smarthome.model.script

My full reply follow, which you may or may not need…

  1. Depends. For quick debugging, I usually set the log level in the console. If I’m going to be doing extensive work I occasionally use the configuration file.
  2. Yes, see my results below.
  3. I don’t know what you’re referring to with that

Karaf commands:

openhab> log:get org.eclipse.smarthome.model.script
Logger                             | Level
------------------------------------------
org.eclipse.smarthome.model.script | INFO
openhab> log:set DEBUG org.eclipse.smarthome.model.script
openhab> log:get org.eclipse.smarthome.model.script
Logger                             | Level
------------------------------------------
org.eclipse.smarthome.model.script | DEBUG

Script:

logDebug("test23", "Hi! I'm a debug statement.")

Log output:

00:41:35.260 [DEBUG] [clipse.smarthome.model.script.test23] - Hi! I'm a debug statement.
0 Likes

Rule will not be startet
(Joseph F. Karnicky) #6

Bingo. I guess I will have to learn to read more carefully. Everything is good now.

Regarding my 3rd question above:
in Java there is a format method which formats arguments into a string.
The syntax is, for example,

String formattedString = String.format("the temperature is %.2f",temp)

where temp is a Double or double. The value of temp will be reported to 2 places. I had seen An example of DEBUG output that used the Java format syntax to format the output of logDebug. However, despite searching all over the place I couldn’t find this example.
Anyway, I found it: it’s here, right where it is supposed to be:
https://docs.openhab.org/administration/logging.html#karaf-console
Thanks again for all the help.
Regards,
Joe

0 Likes