Has anyone else had an issue with the Jython logging no longer producing simple function.log.info statements?
I was running OH2.5.3 via OpenHABian on an Ubuntu server and then got an update to the newer OH2.5.5. On restart my logs are missing the *.log.info output.
My Jython test code:
@rule("Testing stuff - v1")
@when("Item RunJython1 changed")
def testing_1(event):
""" Just random code snippets to test stuff """
testing_1.log.info("Starting 1")
home = items["IsAnyoneHome"]
holiday = items["IsVacation"]
logging.warning("Simple - Home is {}".format(home))
logging.warning("Simple - Holiday is {}".format(holiday))
if items["IsAnyoneHome"] == ON:
logging.warning("Logic - Home is on")
elif items["IsAnyoneHome"] == OFF:
logging.warning("Logic - Home is off")
if items["IsVacation"] == ON:
logging.warning("Logic - Holiday is on")
elif items["IsVacation"] == OFF:
logging.warning("Logic - Holiday is off")
testing_1.log.info("Ending 1")
In OH2.5.3
2020-05-20 08:38:22.762 [INFO ] [jsr223.jython.Testing stuff - v1 ] - Starting 1
2020-05-20 08:38:22.768 [WARN ] [ROOT ] - Simple - Home is ON
2020-05-20 08:38:22.769 [WARN ] [ROOT ] - Simple - Holiday is OFF
2020-05-20 08:38:22.771 [WARN ] [ROOT ] - Logic - Home is on
2020-05-20 08:38:22.773 [WARN ] [ROOT ] - Logic - Holiday is off
2020-05-20 08:38:22.775 [INFO ] [jsr223.jython.Testing stuff - v1 ] - Ending 1
2020-05-20 08:38:22.776 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'f94b9e05-c06b-4474-ad78-287da196a6e3' is executed.
The same Jython function now running in OH2.5.5:
2020-05-20 09:09:02.462 [WARN ] [ROOT ] - Simple - Home is OFF
2020-05-20 09:09:02.464 [WARN ] [ROOT ] - Simple - Holiday is OFF
2020-05-20 09:09:02.466 [WARN ] [ROOT ] - Logic - Home is off
2020-05-20 09:09:02.468 [WARN ] [ROOT ] - Logic - Holiday is off
2020-05-20 09:15:24.699 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '826edb45-f437-4d35-9e2e-b2e47da5105c' is executed.
I have been able to replicate this using OSX runtimes on my Dev machine. No karaf settings changed between the update, and the internal RuleEngine DEBUG messages are still appearing - just not the ones I add to my functions.
Double check your loggers (log:get)… they may have been overwritten. Also, have you restarted a second time since the update? Another thing you could try is to use the beta Jython addon…
So jsr233 is in twice, with jsr223.jython.core & jsr223.jython.core.metadata.
Running the test rules (x3) again, still doesn’t give me the testing.log.info output I’d expect.
I might kick the prod box again and see what happens to the loggers.
The dev runtime on OSX has been re-downloaded and configured ( I should really automate some of that!) and the jsr233 & core.automation are now present and appear to be working.
Check permissions on all of the files (what type of installation are you running?) and manually edit the $OPENHAB_USERDATA/etc/org.ops4j.pax.logging.cfg file.
My prod box is Ubuntu server 18.04 LTS running openhabian. Current 2.5.5-1 release of OpenHAB.
My dev environments are the OSX runtimes. That way I can spin up a new dev environment, copy my .things, .items etc etc across and then just try stuff.
I used to use a RPi, but reload/deployment times when testing was too long!!
Anyway, my permissions were OK, I even ran the openhabian fix permissions config item to make sure.
Eventually I compared the Dev /var/lib/openhab2/etc/org.ops4j.pax.logging.cfg with the one on Prod, and apart from the extra jsr223 entry I could see no differences, so I’ve now copied the file across and restarted.
This appears to have solved the issue - I can see all the things that don’t work now!
On a side note - the custom loggers you discuss here - do these go in the pax.logging.cfg file and replace the existing jsr223 entries? Will these create separate log files for the jsr233 and automation loggers or still in the normal openhab.log?
