Skip to content

Improve Error Reporting for New SQL Engine #88

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.

Sign up for GitHub

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

Merged
forestmvey merged 5 commits into from
Jul 14, 2022
Merged

Improve Error Reporting for New SQL Engine #88

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
38d3819
Initial Implementation
forestmvey Jul 11, 2022
d9bfd6c
Adding JAVADOC and code cleanup
forestmvey Jul 12, 2022
9866cce
Fixing output errors on tests, variable name formatting, minor revisions
forestmvey Jul 12, 2022
05b4c90
Fixed so only successfully anonymized data is logged. Handled stack t…
forestmvey Jul 13, 2022
0467d13
Fix whitespace and add comments on updates for anonymizing string fun…
forestmvey Jul 13, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 18 additions & 0 deletions docs/user/admin/settings.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,15 @@ Result set::
},
"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 [DELETE] at: 'DELETE' <--- HERE... More details: Expecting tokens in {<EOF>, 'DESCRIBE', 'SELECT', 'SHOW', ';'}",
"type": "SyntaxCheckException"
},
"status": 400
}

plugins.sql.slowlog
============================
Expand Down Expand Up @@ -310,4 +319,13 @@ SQL query::
},
"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 [DELETE] at: 'DELETE' <--- HERE... More details: Expecting tokens in {<EOF>, 'DESCRIBE', 'SELECT', 'SHOW', ';'}",
"type": "SyntaxCheckException"
},
"status": 400
}

34 changes: 34 additions & 0 deletions legacy/src/main/java/org/opensearch/sql/legacy/plugin/RestSQLQueryAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,9 +6,12 @@

package org.opensearch.sql.legacy.plugin;

import static org.opensearch.rest.RestStatus.BAD_REQUEST;
import static org.opensearch.rest.RestStatus.INTERNAL_SERVER_ERROR;
import static org.opensearch.rest.RestStatus.OK;
import static org.opensearch.rest.RestStatus.SERVICE_UNAVAILABLE;
import static org.opensearch.sql.executor.ExecutionEngine.QueryResponse;
import static org.opensearch.sql.legacy.plugin.RestSqlAction.isClientError;
import static org.opensearch.sql.protocol.response.format.JsonResponseFormatter.Style.PRETTY;

import java.io.IOException;
Expand All @@ -27,6 +30,7 @@
import org.opensearch.sql.common.response.ResponseListener;
import org.opensearch.sql.common.setting.Settings;
import org.opensearch.sql.executor.ExecutionEngine.ExplainResponse;
import org.opensearch.sql.legacy.executor.format.ErrorMessageFactory;
import org.opensearch.sql.legacy.metrics.MetricName;
import org.opensearch.sql.legacy.metrics.Metrics;
import org.opensearch.sql.opensearch.security.SecurityAccess;
Expand Down Expand Up @@ -61,6 +65,14 @@ public class RestSQLQueryAction extends BaseRestHandler {
*/
private final Settings pluginSettings;

/**
* Captured error message to aggregate diagnostics
* for both legacy and new SQL engines.
* This member variable and it's usage can be deleted once the
* legacy SQL engine is deprecated.
*/
private String errorStr;

/**
* Constructor of RestSQLQueryAction.
*/
Expand All @@ -85,6 +97,22 @@ protected RestChannelConsumer prepareRequest(RestRequest request, NodeClient nod
throw new UnsupportedOperationException("New SQL handler is not ready yet");
}

/**
* Setter for errorStr member variable.
* @param error : String error value to set member variable.
*/
public void setErrorStr(String error) {
errorStr = error;
}

/**
* Getter for errorStr member variable.
* @return : errorStr member variable.
*/
public String getErrorStr() {
return errorStr;
}

/**
* Prepare REST channel consumer for a SQL query request.
* @param request SQL request
Expand All @@ -109,6 +137,12 @@ public RestChannelConsumer prepareRequest(SQLQueryRequest request, NodeClient no
if (request.isExplainRequest()) {
LOG.info("Request is falling back to old SQL engine due to: " + e.getMessage());
}

/**
* Setting errorStr member variable is used to aggregate error messages when both legacy and new SQL engines fail.
* This implementation can be removed when the legacy SQL engine is deprecated.
*/
setErrorStr(ErrorMessageFactory.createErrorMessage(e, isClientError(e) ? BAD_REQUEST.getStatus() : SERVICE_UNAVAILABLE.getStatus()).toString());
return NOT_SUPPORTED_YET;
}

Expand Down
47 changes: 41 additions & 6 deletions legacy/src/main/java/org/opensearch/sql/legacy/plugin/RestSqlAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@

import com.alibaba.druid.sql.parser.ParserException;
import com.google.common.collect.ImmutableList;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.sql.SQLFeatureNotSupportedException;
import java.util.Arrays;
import java.util.HashMap;
Expand Down Expand Up @@ -118,6 +121,13 @@ public String getName() {
return "sql_action";
}

/**
* Prepare and execute rest SQL request. In the event the V2 SQL engine fails, the V1
* engine attempts the query.
* @param request : Rest request being made.
* @param client : Rest client for making the request.
* @return : Resulting values for request.
*/
@Override
protected RestChannelConsumer prepareRequest(RestRequest request, NodeClient client) {
Metrics.getInstance().getNumericalMetric(MetricName.REQ_TOTAL).increment();
Expand Down Expand Up @@ -161,8 +171,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()));
logAndPublishMetrics(e);
return channel -> reportError(channel, e, isClientError(e) ? BAD_REQUEST : SERVICE_UNAVAILABLE);
return channel -> reportError(channel, e, isClientError(e) ? BAD_REQUEST : SERVICE_UNAVAILABLE, newSqlQueryHandler.getErrorStr());
}
}

Expand All @@ -180,14 +191,27 @@ private void handleCursorRequest(final RestRequest request, final String cursor,
cursorRestExecutor.execute(client, request.params(), channel);
}

/**
* Log error message for exception and increment failure statistics.
* @param e : Caught exception.
*/
private static void logAndPublishMetrics(final Exception e) {
/**
* Use PrintWriter to copy the stack trace for logging. This is used to anonymize
* log messages, and can be reverted to the simpler implementation when
* the anonymizer is fixed.
*/
StringWriter sw = new StringWriter();
e.printStackTrace(new PrintWriter(sw));
String stackTrace = sw.toString();
if (isClientError(e)) {
LOG.error(LogUtils.getRequestId() + " Client side error during query execution", e);
LOG.error(LogUtils.getRequestId() + " Client side error during query execution", QueryDataAnonymizer.anonymizeData(e.getMessage()));
Metrics.getInstance().getNumericalMetric(MetricName.FAILED_REQ_COUNT_CUS).increment();
} else {
LOG.error(LogUtils.getRequestId() + " Server side error during query execution", e);
LOG.error(LogUtils.getRequestId() + " Server side error during query execution", QueryDataAnonymizer.anonymizeData(e.getMessage()));
Metrics.getInstance().getNumericalMetric(MetricName.FAILED_REQ_COUNT_SYS).increment();
}
LOG.error(stackTrace);
}

private static QueryAction explainRequest(final NodeClient client, final SqlRequest sqlRequest, Format format)
Expand Down Expand Up @@ -234,7 +258,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) {
return e instanceof NullPointerException // NPE is hard to differentiate but more likely caused by bad query
|| e instanceof SqlParseException
|| e instanceof ParserException
Expand All @@ -253,8 +277,19 @@ private void sendResponse(final RestChannel channel, final String message, final
channel.sendResponse(new BytesRestResponse(status, message));
}

private void reportError(final RestChannel channel, final Exception e, final RestStatus status) {
sendResponse(channel, ErrorMessageFactory.createErrorMessage(e, status.getStatus()).toString(), status);
/**
* Report Error message to user.
* @param channel : Rest channel to sent response through.
* @param e : Exception caught when attempting query.
* @param status : Status for rest request made.
* @param v2SqlEngineError : Error message for new SQL engine. Can be removed when old SQL engine is deprecated.
*/
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;
sendResponse(channel, errorMsg, status);
}

private boolean isSQLFeatureEnabled() {
Expand Down
8 changes: 5 additions & 3 deletions legacy/src/main/java/org/opensearch/sql/legacy/utils/QueryDataAnonymizer.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,8 @@ public class QueryDataAnonymizer {
* Sensitive data includes index names, column names etc.,
* which in druid parser are parsed to SQLIdentifierExpr instances
* @param query entire sql query string
* @return sql query string with all identifiers replaced with "***"
* @return sql query string with all identifiers replaced with "***" on success
* and failure string otherwise to ensure no non-anonymized data is logged in production.
*/
public static String anonymizeData(String query) {
String resultQuery;
Expand All @@ -38,8 +39,9 @@ public static String anonymizeData(String query) {
.replaceAll("false", "boolean_literal")
.replaceAll("[\\n][\\t]+", " ");
} catch (Exception e) {
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

@Yury-Fridlyand Yury-Fridlyand Jul 14, 2022

Choose a reason for hiding this comment

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

You still print the query on failure in the log.

Copy link
Author

@forestmvey forestmvey Jul 14, 2022

Choose a reason for hiding this comment

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

Only in debug level which shouldn't be enabled in a production build right?

resultQuery = "Failed to anonymize data.";
Copy link

@acarbonetto acarbonetto Jul 13, 2022

Choose a reason for hiding this comment

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

We should comment why we aren't returning the query any longer

}
return resultQuery;
}
Expand Down