to 1.2.4: Add trace logging and consistent logging #932
Conversation
kentbull
force-pushed
the
add-trace-logging-and-consistent-logging
branch
from
bbcf39c to
e0c5fde
Compare
kentbull
force-pushed
the
add-trace-logging-and-consistent-logging
branch
from
e0c5fde to
51d8cd7
Compare
There was a problem hiding this comment.
I would like to find a way to avoid the prefixes added to all the log messages.
Most log messages are unique enough that a simple search of the code base finds the one you are looking for. And if they aren't, I'd rather update the few that are to be more specific / descriptive and avoid this bespoke cataloging of log messages.
kentbull
changed the title
I agree that it does add some noise, though I believe it is well worth the tradeoff, especially for newcomers like me. I added a module prefix in most places and in some places I added the identifier prefix. The reason I added this is because while debugging multisig I had the question of which multisig participant was receiving a message or completing a multisig group. If there's a different or better way to accomplish this understanding I'm all ears. Adding prefixes to the log messages really helped especially when I wanted to distinguish between things like the KERIA Anchorer and the KERIpy Anchorer and similar cases. I like being able to follow the log messages without having to refer back to the codebase, though that is personal preference. I'll go remove the prefixes if you'd rather have them be removed. |
|
Can we configure the logger to just (optionally?) prefix logs with the module and class name? I do agree that it would be nice to get this info when less familiar with the code as jumping back to search for log line by line is a lot of context to keep in mind trying to debug. |
|
@iFergal no, sadly that does not work because the HIO logger always uses the "hio.ogler.help" module as the module name, sadly. |
I believe Fergal is correct. You can configure the logger after retrieving it in whatever application starts your logging and with that configuration you could add something like %{packagePath)s.%(module)s in the format string. All of my applications override the module name when I start my loggers. |
|
For example, the logging for my RACK gateways looks like this:
|
I will try it again. When I tried to add the module name to the logger format like you say it always returned @pfeairheller do you mind posting how you got HIO's logger to include the module name? I see the app name Adding the app prefix like you have is easy. The thing that did not work for me is the module name, which is why I added it manually to all the log messages I wrote at the INFO level. |
|
So here it is with package, function name and line number:
The format string for this was:
And here is the full list of formatting fields: %(asctime)s: Human-readable time when the log record was created. |
|
I think in debug we could change the formatter to use those fields with some combination of file, path, package, function and line number. Formatter better than my quick example above. |
|
@iFergal and @pfeairheller the most recent commit contains a format string added in the This next snippet shows the first 81 characters of the log message using the first formatter shown below. This is from the following format string: logFmt = "%(asctime)s [keri] %(module)s.%(funcName)s-%(lineno)d %(levelname)-8s %(message)s"The log snippet above is from logs of what it looks like on my machine to run I like the more trim logging format shown next: logFmt = "%(asctime)s [keri] %(levelname)-8s %(message)s"which produces log output that looks like: this is 57 characters of metadata before the message is reached. I like the more detailed INFO loggers yet a nice middle ground seems to be the more trim logging format shown above. I did make an attempt at adding separate debug and info loggers in the place where the app starts so that we could have cleaner INFO logs and more detailed DEBUG logs yet the class Ogler():
...
def getLogger(self, name=__name__, level=None):
"""
Returns Basic Logger
default is to name logger after module
"""
logger = logging.getLogger(name)
logger.propagate = False # disable propagation of events
level = level if level is not None else self.level
logger.setLevel(level)
for handler in list(logger.handlers): # remove so no duplicate handlers
logger.removeHandler(handler)
if self.consoled:
logger.addHandler(self.baseConsoleHandler)
if self.syslogged:
logger.addHandler(self.baseSysLogHandler)
if self.filed and self.opened:
logger.addHandler(self.baseFileHandler)
return loggerAre we okay with either one of the two log format strings I showed here? |
This PR adds the logging changes made to 1.1.27+ from here: #913
and from here: #930
There is be a similar PR to the
mainbranch: #933The result of this PR is: