Change logging formatting to lazily evaluate (performance critical) #59
Conversation
| Thank you for your pull request and welcome to our community. We require contributors to sign our Contributor License Agreement, and we don't seem to have you on file. In order for us to review and merge your code, please submit the signed CLA to cla@prestosql.io. For more information, see https://github.com/prestosql/cla. |
| Thank you for your pull request and welcome to our community. We require contributors to sign our Contributor License Agreement, and we don't seem to have you on file. In order for us to review and merge your code, please submit the signed CLA to cla@prestosql.io. For more information, see https://github.com/prestosql/cla. |
| "redirect {} from {} to {}".format( | ||
| http_response.status_code, location, url | ||
| ) | ||
| "redirect {} from {} to {}", |
There was a problem hiding this comment.
That's definitely a good improvement!
nit: do you think it would be ok to format this in one line
logger.info("redirect {} from {} to {}", http_response.status_code, location, url) ?
(BTW i think this could go at debug level, but that's perhaps out of scope of this PR)
There was a problem hiding this comment.
Yeah of course @ formatting :)
| logger = logging.getLogger(name) | ||
| logger.setLevel(log_level) | ||
| return logger | ||
| return FormatLogger(logger) |
There was a problem hiding this comment.
What are the builtin logging's formatting capabilities?
Is there something we could use to avoid adding a wrapper?
There was a problem hiding this comment.
The builtin logging's simplest formatting capabilities can allow you to lazily log in the old python2 syntax:
logging.log("%s", something) There currently is no support for python 3 formatting due to ambiguous kwargs that might arise. In general, python2 style is not encouraged. @ wrapper, the LoggingAdapter is actually a pattern that python suggests on using - we're not actually adding any overhead because all I've done is replace the string processing function on the logger level :)
There was a problem hiding this comment.
IMo the old-school %s formatting is good enough for our modest needs.
I would rather keep the code simple using what is immediately available from the standard library -- and wait for the standard library to gain more reach formatting options.
There was a problem hiding this comment.
sure, I can open another PR for that instead 👍
| I believe this has been replaced with #60, so let me close this. |
2 participants
When comparing
presto-python-clientwithpyhivefor performance reasons, I found this client to run extremely slow for queries with large throughput. Runningline_profileronfetchall(), we see this:Zooming into two lines:
We see that although our
LEVELis set toINFO, the formatting on these strings are done eagerly and then discarded. The formatting itself takes a whole 7 seconds and 6 seconds respectively out of 43 seconds. For context, Pyhive takes roughly 28 seconds. The exact setup to reproduce this benchmark is redacted, but a comparable benchmark could be runningSELECT * FROM some_big_tablefrom a localhost coordinator. We would love to use this presto client in our production workflow but with the performance issue here we have decided not to consider it until a fix has been applied.To do this, people typically use
logging.info("%s", x)syntax. However, the official python docs don't encourage this style. So how can we uselogging.info("{}", x), preserving our original logs and formatting style? The change here is a common one - the logging library provides a LoggerAdapter class that allow us to return a "logger" of the same API but perform python3 formatting style only if the level is appropriate (lazily evaluated). For example, see the official python cookbook.