Logger infoDuration

I was curious if its possible to use the .infoDuration methods outlined in the java docs on the LoggerEx class provided by system.util.getLogger().

It seems that jython isn’t actually implementing the __enter__ and __exit__ methods on the Closeable interface, so I tried adding them manually, but I can’t seem to get an accurate print out in the logs

i.e.

import time
logger = system.util.getLogger("TEST")

class test():
	def __init__(self, closeable):
		self.closeable = closeable
	
	def __enter__(self):
		pass
	
	def __exit__(self, exc_type, exc_value, exc_traceback):
		self.closeable.close()


with test(logger.infoDuration("Debugging sleep")):
	time.sleep(1)

Will actually just print out the following in the logs. Not really able to get my debugging message, or the duration information.

INFO TEST - START - {}
INFO TEST - FINISHED {} - {}

I appreciate any ideas, this would be nice to be able to use for runtime debugging without having to go back and implement by own test context manager anywhere I am already using a dedicated logger.

Oof.

That’s embarrassing. You’re not missing anything - the xDuration logger closeables simply don’t work. We’re not using them anywhere in our codebase, so no one’s ever noticed.

You’re not really missing a whole lot. Basically the final logged message is (supposed) to be using FormatUtil.formatDuration to make a human-readable elapsed time:
http://files.inductiveautomation.com/sdk/javadoc/ignition80/8.0.12/com/inductiveautomation/ignition/common/FormatUtil.html
But the precision is fairly low so it’s probably not very useful anyways. I’d just make your own. You can use java.lang.System.nanoTime() for a monotonic clock with nanosecond precision.

2 Likes

Lol I appreciate the candid-ness!

I incidentally fixed these format strings with some other work I was doing in 8.1.18.