Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

improved JDBC logging #11676

Merged
merged 4 commits into from
Sep 16, 2021
Merged

Conversation

clintropolis
Copy link
Member

Description

This started out as a quest to make JDBC debug level logging slightly more verbose to get a better idea of what is happening, but in the process realized that there are quite a lot of cases where we actually aren't logging any exceptions at all whenever jdbc queries fail; all that is visible is the debug logs indicate that a connection was closed and the client might get a useful error message if it is lucky, but good luck beyond that.

I couldn't find an easy way to add any sort of centralized error logging for any caught exception in the DruidAvaticaJsonHandler, so, I added utility methods to DruidMeta to slightly make the 'log and throw' pattern a bit more concise. I don't love it, but at least it makes exceptions actually be logged in the broker in a lot of cases we were missing. To err on the side of caution i essentially went through and looked for places where we were throwing some exception to the wind without any obvious catcher in Druid code (hopefully there should be no duplicates).

Additionally, I made router debug logs slightly more chatty, including printing query ids when used with a broker selection strategy that parses the query at the router. This log really doesn't add much, since AsyncQueryForwardingServlet is quite chatty already from the base class structure it picks up by being a AsyncProxyServlet, but does at least print some things in Druid terms I guess.

This will probably fail CI because its all log messages and didn't add any tests...


This PR has:

  • been self-reviewed.
  • been tested in a test Druid cluster.


public static <T extends Throwable> T logFailure(T error)
{
LOG.noStackTrace().error(error, error.getMessage());
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why this function does not log stack trace?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, I guess I was trying to match the behavior here when logging errors in QueryLifecycle, but maybe these are worth having the stack trace handy since I guess they are only happening outside the query lifecycle so maybe more interesting. I'm going to change it I think

Copy link
Member

@FrankChen021 FrankChen021 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. Only leaves a question.

@@ -219,6 +219,7 @@ protected void service(HttpServletRequest request, HttpServletResponse response)
String connectionId = getAvaticaProtobufConnectionId(protobufRequest);
targetServer = hostFinder.findServerAvatica(connectionId);
request.setAttribute(AVATICA_QUERY_ATTRIBUTE, requestBytes);
LOG.debug("Forwarding protobuf JDBC connection [%s] to broker [%s]", connectionId, targetServer);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should there be an option to make these newly added debug logs be info level? I've always found the router logs to be basically worthless unless stuff is exploding, and letting it print stuff about what it is forwarding to where without the overhead of the massive amount of debug level logs might be useful.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thinking further about this I think would be better handled if the routing logic was just moved out of AsyncQueryForwardingServlet into some dedicated query router class that does the routing logic, then these new logs would live in that class and debug logging could more selectively just enable those logs (without picking up all the underlying jetty servlet debug logs).

@clintropolis clintropolis merged commit 3044372 into apache:master Sep 16, 2021
@clintropolis clintropolis deleted the jdbc-debug-logs branch September 16, 2021 08:28
@abhishekagarwal87 abhishekagarwal87 added this to the 0.23.0 milestone May 11, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants