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

Improve Error Reporting for New SQL Engine #691

Conversation

forestmvey
Copy link
Collaborator

Description

When a query fails both legacy and new SQL engines, only the legacy engine error is reported to the user. On failure in both the legacy and new SQL engines, error messages from both should be reported to the end user. To avoid logging un-anonymized data, the anonymizer now returns a failure to anonymize string.

Check List

  • New functionality includes testing.
    • All tests pass, including unit test, integration test and doctest
  • New functionality has been documented.
    • New functionality has javadoc added
    • New functionality has user manual doc added
  • Commits are signed per the DCO using --signoff

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.
For more information on following Developer Certificate of Origin and signing off your commits, please check here.

@forestmvey forestmvey requested a review from a team as a code owner July 14, 2022 17:21
LOG.warn("Caught an exception when anonymizing sensitive data");
resultQuery = query;
LOG.warn("Caught an exception when anonymizing sensitive data.");
LOG.debug("String {} failed anonymization.", query);
Copy link
Collaborator

@penghuo penghuo Jul 14, 2022

Choose a reason for hiding this comment

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

Why not combine with LOG.warn?

Copy link
Collaborator

Choose a reason for hiding this comment

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

For syntax errors, the query variable contains the details of the failed query and is not anonymized (since the anonymization failed). This could, potentially, put sensitive data into the logs that we don't want to be included in production data. Setting it to debug level means that it doesn't go out to the logs by default.

Comment on lines 112 to 120
Query failed on both V1 and V2 SQL parser engines. V2 SQL parser error following:
{
"error": {
"reason": "Invalid SQL query",
"details": "Failed to parse query due to offending symbol [DELETE] at: 'DELETE' <--- HERE... More details: Expecting tokens in {<EOF>, 'DESCRIBE', 'SELECT', 'SHOW', ';'}",
"type": "SyntaxCheckException"
},
"status": 400
}
Copy link
Collaborator

Choose a reason for hiding this comment

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

1.Comparing with previous error message, the new one is misleading.
2.Why the V2 engine throw syntax exception? SQLFeatureDisabledException means user already disable sql plugin, then query will not executed in SQL engine.

Copy link
Collaborator Author

@forestmvey forestmvey Jul 15, 2022

Choose a reason for hiding this comment

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

Good catch on this bug. Looks like the error string value for the V2 engine was being used from a previous error. I will update the test and clear the error message with each attempt at the V1 and V2 engines.

@codecov-commenter
Copy link

codecov-commenter commented Jul 15, 2022

Codecov Report

Merging #691 (0898159) into main (592c58b) will not change coverage.
The diff coverage is n/a.

@@            Coverage Diff            @@
##               main     #691   +/-   ##
=========================================
  Coverage     94.74%   94.74%           
  Complexity     2857     2857           
=========================================
  Files           283      283           
  Lines          7676     7676           
  Branches        560      560           
=========================================
  Hits           7273     7273           
  Misses          349      349           
  Partials         54       54           
Flag Coverage Δ
query-workbench 62.76% <ø> (ø)
sql-engine 97.74% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

Help us with your feedback. Take ten seconds to tell us how you rate us.

* This member variable and it's usage can be deleted once the
* legacy SQL engine is deprecated.
*/
private String errorStr;
Copy link
Collaborator

Choose a reason for hiding this comment

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

You can use @Getter and @Setter annotations instead of creating setErrorStr and getErrorStr.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Copy link
Collaborator

Choose a reason for hiding this comment

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

Just want to confirm is this class (or RestSqlAction who create this) a singleton or created per request?

Copy link
Collaborator

Choose a reason for hiding this comment

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

do we really need errorStr? or Exception e? Could we use RestSqlAction produce the error message from e.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

@dai-chen This class is a singleton.
@penghuo We need to be able to capture error messages form potentially 2 exceptions. That is why we need the errorStr member variable.

Copy link
Collaborator

Choose a reason for hiding this comment

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

RestSqlAction is created per request.

*/
StringWriter sw = new StringWriter();
e.printStackTrace(new PrintWriter(sw));
String stackTrace = sw.toString();
Copy link
Collaborator

Choose a reason for hiding this comment

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

Can't his block (205-207) be with line 215? It'll be easier to follow.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Copy link
Collaborator

Choose a reason for hiding this comment

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

It is for debug purpose, right? could it be wrap inside if (log.debug)?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

We want the stack trace to be logged under normal debug levels as error. So not for debugging purposes only but error reporting like prior to this new implementation. I could wrap this inside of a Log.Error if that is more of your liking.

Signed-off-by: forestmvey <[email protected]>
…race separately in log to avoid logging un-anonymized data. Added function comments

Signed-off-by: forestmvey <[email protected]>
…Added more diagnostics for unsupported SQL requests. Updated documentation with fixes in the test that reflects V2 error message being used where it shouldn't

Signed-off-by: forestmvey <[email protected]>
@forestmvey forestmvey force-pushed the integ-sql_engine_error_improvements branch from eab8d62 to 0898159 Compare July 25, 2022 15:58
@Override
protected RestChannelConsumer prepareRequest(RestRequest request, NodeClient client) {
Metrics.getInstance().getNumericalMetric(MetricName.REQ_TOTAL).increment();
Metrics.getInstance().getNumericalMetric(MetricName.REQ_COUNT_TOTAL).increment();

LogUtils.addRequestId();
newSqlQueryHandler.setErrorStr("");
Copy link
Collaborator

Choose a reason for hiding this comment

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

Is it necessary?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Since this class is a singleton we can potentially re-use old error messages. This ensures we are starting with an empty error message.

Copy link
Member

Choose a reason for hiding this comment

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

if it's singleton will errorStr handle concurrent errors?

@@ -234,7 +260,7 @@ private static boolean isExplainRequest(final RestRequest request) {
return request.path().endsWith("/_explain");
}

private static boolean isClientError(Exception e) {
public static boolean isClientError(Exception e) {
Copy link
Collaborator

Choose a reason for hiding this comment

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

why change to public?

Copy link
Collaborator Author

@forestmvey forestmvey Aug 5, 2022

Choose a reason for hiding this comment

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

I updated this function to public to allow RestSqlQueryAction to output the same error format as this class. As well it seemed like a function that would be appropriately public.

Comment on lines +289 to +293
private void reportError(final RestChannel channel, final Exception e, final RestStatus status, String v2SqlEngineError) {
String errorMsg = ErrorMessageFactory.createErrorMessage(e, status.getStatus()).toString();
errorMsg += v2SqlEngineError.isEmpty() ? "" :
"\nQuery failed on both V1 and V2 SQL parser engines. V2 SQL parser error following: \n"
+ v2SqlEngineError;
Copy link
Collaborator

Choose a reason for hiding this comment

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

Just discovered that you're concatenating 2 json objects here. In my test I'm getting

{
  "error": {
    "reason": "Invalid SQL query",
    "details": "unsupported method: simple_query_string",
    "type": "SqlParseException"
  },
  "status": 400
}
Query failed on both V1 and V2 SQL parser engines. V2 SQL parser error following:
{
  "error": {
    "reason": "Invalid SQL query",
    "details": "Failed to parse query due to offending symbol [1] at: 'select `key`, str2 from calcs where simple_query_string([str2], one, analyzer = standard, 1' <--- HERE... More details: Expecting tokens in {'ALLOW_LEADING_WILDCARD', 'ANALYZER', 'ANALYZE_WILDCARD', 'AUTO_GENERATE_SYNONYMS_PHRASE_QUERY', 'BOOST', 'CUTOFF_FREQUENCY', 'DEFAULT_FIELD', 'DEFAULT_OPERATOR', 'ESCAPE', 'ENABLE_POSITION_INCREMENTS', 'FIELDS', 'FLAGS', 'FUZZINESS', 'FUZZY_MAX_EXPANSIONS', 'FUZZY_PREFIX_LENGTH', 'FUZZY_REWRITE', 'FUZZY_TRANSPOSITIONS', 'LENIENT', 'LOW_FREQ_OPERATOR', 'MAX_DETERMINIZED_STATES', 'MAX_EXPANSIONS', 'MINIMUM_SHOULD_MATCH', 'OPERATOR', 'PHRASE_SLOP', 'PREFIX_LENGTH', 'QUOTE_ANALYZER', 'QUOTE_FIELD_SUFFIX', 'REWRITE', 'SLOP', 'TIE_BREAKER', 'TIME_ZONE', 'TYPE', 'ZERO_TERMS_QUERY'}",
    "type": "SyntaxCheckException"
  },
  "status": 400
}

You should update details block of ErrorMessage instead.

@@ -161,8 +172,9 @@ protected RestChannelConsumer prepareRequest(RestRequest request, NodeClient cli
final QueryAction queryAction = explainRequest(client, sqlRequest, format);
return channel -> executeSqlRequest(request, queryAction, client, channel);
} catch (Exception e) {
LOG.error(LogUtils.getRequestId() + " V2 SQL error during query execution", QueryDataAnonymizer.anonymizeData(newSqlQueryHandler.getErrorStr()));
Copy link
Collaborator

Choose a reason for hiding this comment

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

errorStr never holds the query, so call to anonymizer will always fail.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants