feat: add support to log commit stats

[larkee]

This PR adds support for logging commit statistics when requested by the user via log_commit_stats.

Commit statistics will be logged at the INFO log level.

The default logger will log commit stats using sys.stderr, however the user can pass their own logger when constructing the database if needed.

A sample of how to use the feature is given below:

database = instance.database(database_id, logger=custom_logger)
database.log_commit_stats = True

Once log_commit_stats is set, commit stats will be logged via the database logger any time commit is called by the library.

[busunkim96]

Stamping for the samples noxfile update.

[busunkim96]

The logging bits look good to me, but I haven't worked much with loggers. 🙈

@daniel-sanche would you be able to review this? Are there any best practices to ensure client library logs work nicely with the Observability products?

[daniel-sanche]

Are there any best practices to ensure client library logs work nicely with the Observability products?

I think that really depends on where this code is run, since different GCP environments have different logging policies. Many GCP environments work best if the log is printed as structured JSON, but that isn't supported everywhere. If we want to make sure the logs look good in Cloud Logging no matter where it's run, right now the best option is probably to include the logging client library here.

But if we want to avoid the new dependency, I'd say the best option would be to print a simple message to stdout, without extra formatting.

[larkee]

@daniel-sanche Thank you for the feedback!

I've removed the formatter and passed the CommitStats object directly to the info calls. This means the default behavior will print the CommitStats object to std_out, e.g.

mutation_count: 2

Users can use a custom logger with a formatter to suit their logging needs, or a custom logger which overloads info method and has access to the CommitStats object, e.g.

class CustomLogger(logging.Logger):
def __init__(self):
self._last_commit_stats = None
def info(self, commit_stats):
self._last_commit_stats = commit_stats
super().info(commit_stats)
def get_last_commit_stats():
return self._last_commit_stats

I think this is a much better design. WDYT?

[daniel-sanche]

For the most part that seems good to me, I think it's a good idea to just write the stats to stdout, and let the user override formatting/handlers if they decide to.

I'm not sure if I understand the CustomLogger part though. It's not a good idea to re-interpret the input to info like that in a logger subclass. It seems like you might want to pass in commit_stats in the extra argument. That would allow users to reference it in format strings, or access it in custom Handler classes

[daniel-sanche]

I wnet over this in my other comment, but I'll repeat it here too: The docs for Python Logging say they expect the main msg argument to be a string. If you want to add a custom object, see the extra argument

[larkee]

Ah, that's exactly what I want. I've updated the call to use a formatted message and pass the CommitStats via the extra argument. Thank you for your patience while I learn how to use loggers correctly 👍

[daniel-sanche]

No problem! Yeah this now LGTM from a logging perspective

[gcf-merge-on-green]

Merge-on-green attempted to merge your PR for 6 hours, but it was not mergeable because either one of your required status checks failed, one of your required reviews was not approved, or there is a do not merge label. Learn more about your required status checks here: https://help.github.com/en/github/administering-a-repository/enabling-required-status-checks. You can remove and reapply the label to re-run the bot.