diff --git a/external-service-impl/rest/pom.xml b/external-service-impl/rest/pom.xml index fc064d28254ec..ec1b7b1f59a10 100644 --- a/external-service-impl/rest/pom.xml +++ b/external-service-impl/rest/pom.xml @@ -34,6 +34,16 @@ UTF-8 + + ch.qos.logback + logback-classic + test + + + ch.qos.logback + logback-core + test + org.glassfish.jersey.inject jersey-hk2 diff --git a/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v1/handler/ExceptionHandler.java b/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v1/handler/ExceptionHandler.java index 62f3da75f639e..635572b4ef739 100644 --- a/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v1/handler/ExceptionHandler.java +++ b/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v1/handler/ExceptionHandler.java @@ -27,6 +27,7 @@ import org.apache.iotdb.db.exception.StorageEngineException; import org.apache.iotdb.db.exception.metadata.DatabaseNotSetException; import org.apache.iotdb.db.exception.sql.StatementAnalyzeException; +import org.apache.iotdb.db.utils.ErrorHandlingUtils; import org.apache.iotdb.rest.protocol.exception.RequestLimitExceededException; import org.apache.iotdb.rest.protocol.v1.model.ExecutionStatus; import org.apache.iotdb.rpc.TSStatusCode; @@ -89,7 +90,7 @@ public static ExecutionStatus tryCatchException(Exception e) { responseResult.setMessage(e.getMessage()); responseResult.setCode(TSStatusCode.INTERNAL_SERVER_ERROR.getStatusCode()); } - LOGGER.warn(e.getMessage(), e); + ErrorHandlingUtils.logQueryException(LOGGER, e.getMessage(), responseResult.getCode(), e); return responseResult; } diff --git a/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v2/handler/ExceptionHandler.java b/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v2/handler/ExceptionHandler.java index 9ed5111c7e7ce..1ca0c48bd4896 100644 --- a/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v2/handler/ExceptionHandler.java +++ b/external-service-impl/rest/src/main/java/org/apache/iotdb/rest/protocol/v2/handler/ExceptionHandler.java @@ -27,6 +27,7 @@ import org.apache.iotdb.db.exception.StorageEngineException; import org.apache.iotdb.db.exception.metadata.DatabaseNotSetException; import org.apache.iotdb.db.exception.sql.StatementAnalyzeException; +import org.apache.iotdb.db.utils.ErrorHandlingUtils; import org.apache.iotdb.rest.protocol.exception.RequestLimitExceededException; import org.apache.iotdb.rest.protocol.model.ExecutionStatus; import org.apache.iotdb.rpc.TSStatusCode; @@ -89,7 +90,7 @@ public static ExecutionStatus tryCatchException(Exception e) { responseResult.setMessage(e.getMessage()); responseResult.setCode(TSStatusCode.INTERNAL_SERVER_ERROR.getStatusCode()); } - LOGGER.warn(e.getMessage(), e); + ErrorHandlingUtils.logQueryException(LOGGER, e.getMessage(), responseResult.getCode(), e); return responseResult; } diff --git a/external-service-impl/rest/src/test/java/org/apache/iotdb/rest/protocol/handler/ExceptionHandlerTest.java b/external-service-impl/rest/src/test/java/org/apache/iotdb/rest/protocol/handler/ExceptionHandlerTest.java new file mode 100644 index 0000000000000..2677c5214cabd --- /dev/null +++ b/external-service-impl/rest/src/test/java/org/apache/iotdb/rest/protocol/handler/ExceptionHandlerTest.java @@ -0,0 +1,162 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.iotdb.rest.protocol.handler; + +import org.apache.iotdb.commons.exception.IoTDBException; +import org.apache.iotdb.commons.exception.SemanticException; +import org.apache.iotdb.rpc.TSStatusCode; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import org.antlr.v4.runtime.misc.ParseCancellationException; +import org.junit.Test; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; +import org.slf4j.LoggerFactory; + +import java.util.Arrays; +import java.util.Collection; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertNull; + +@RunWith(Parameterized.class) +public class ExceptionHandlerTest { + @Parameterized.Parameters(name = "REST v{0}") + public static Collection versions() { + return Arrays.asList(new Object[][] {{1}, {2}}); + } + + private final int version; + + public ExceptionHandlerTest(int version) { + this.version = version; + } + + @Test + public void testParseAndSemanticErrorsDoNotLogStackTraces() { + assertException( + new ParseCancellationException("invalid SQL"), TSStatusCode.SQL_PARSE_ERROR, Level.INFO); + assertException( + new SemanticException("invalid query"), TSStatusCode.SEMANTIC_ERROR, Level.INFO); + } + + @Test + public void testExpectedStatusCodesDoNotLogStackTraces() { + for (TSStatusCode code : + new TSStatusCode[] { + TSStatusCode.SQL_PARSE_ERROR, + TSStatusCode.SEMANTIC_ERROR, + TSStatusCode.NO_PERMISSION, + TSStatusCode.ILLEGAL_PATH, + TSStatusCode.NUMERIC_VALUE_OUT_OF_RANGE, + TSStatusCode.DIVISION_BY_ZERO, + TSStatusCode.DATE_OUT_OF_RANGE, + TSStatusCode.UDF_LOAD_CLASS_ERROR, + TSStatusCode.PLAN_FAILED_NETWORK_PARTITION, + TSStatusCode.SYNC_CONNECTION_ERROR, + TSStatusCode.CANNOT_FETCH_FI_STATE, + TSStatusCode.TEMPLATE_INCOMPATIBLE, + TSStatusCode.PATH_ALREADY_EXIST, + TSStatusCode.PIPE_NOT_EXIST_ERROR, + TSStatusCode.QUERY_TIMEOUT, + TSStatusCode.LBAC_ACCESS_DENIED, + TSStatusCode.INVALID_LABEL_VALUE, + TSStatusCode.TABLE_NOT_EXISTS, + TSStatusCode.TABLE_ALREADY_EXISTS, + TSStatusCode.COLUMN_NOT_EXISTS, + TSStatusCode.COLUMN_ALREADY_EXISTS, + TSStatusCode.NO_AVAILABLE_REPLICA, + TSStatusCode.QUERY_EXECUTION_MEMORY_NOT_ENOUGH, + TSStatusCode.EXECUTE_UDF_ERROR, + TSStatusCode.CANNOT_READ_TSFILE, + TSStatusCode.COPY_TO_WRITE_ERROR, + TSStatusCode.METADATA_LEASE_FENCED, + TSStatusCode.METADATA_LEASE_FENCED_RETRY_REQUIRED + }) { + assertException( + new IoTDBException("expected failure", code.getStatusCode()), code, Level.INFO); + } + } + + @Test + public void testUnexpectedErrorsKeepStackTraces() { + assertException( + new NullPointerException("unexpected failure"), + TSStatusCode.INTERNAL_SERVER_ERROR, + Level.WARN); + assertException( + new IoTDBException("query failure", TSStatusCode.QUERY_PROCESS_ERROR.getStatusCode()), + TSStatusCode.QUERY_PROCESS_ERROR, + Level.WARN); + } + + @Test + public void testStorageEngineNotReadyIsNotLogged() { + assertException( + new IoTDBException("not ready", TSStatusCode.STORAGE_ENGINE_NOT_READY.getStatusCode()), + TSStatusCode.STORAGE_ENGINE_NOT_READY, + null); + } + + private void assertException(Exception exception, TSStatusCode code, Level expectedLevel) { + Logger logger = + (Logger) + LoggerFactory.getLogger( + version == 1 + ? org.apache.iotdb.rest.protocol.v1.handler.ExceptionHandler.class + : org.apache.iotdb.rest.protocol.v2.handler.ExceptionHandler.class); + Level originalLevel = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.INFO); + try { + if (version == 1) { + org.apache.iotdb.rest.protocol.v1.model.ExecutionStatus response = + org.apache.iotdb.rest.protocol.v1.handler.ExceptionHandler.tryCatchException(exception); + assertEquals(code.getStatusCode(), response.getCode().intValue()); + assertEquals(exception.getMessage(), response.getMessage()); + } else { + org.apache.iotdb.rest.protocol.model.ExecutionStatus response = + org.apache.iotdb.rest.protocol.v2.handler.ExceptionHandler.tryCatchException(exception); + assertEquals(code.getStatusCode(), response.getCode().intValue()); + assertEquals(exception.getMessage(), response.getMessage()); + } + assertEquals(expectedLevel == null ? 0 : 1, appender.list.size()); + if (expectedLevel != null) { + ILoggingEvent event = appender.list.get(0); + assertEquals(expectedLevel, event.getLevel()); + assertEquals(exception.getMessage(), event.getFormattedMessage()); + if (expectedLevel == Level.INFO) { + assertNull(event.getThrowableProxy()); + } else { + assertNotNull(event.getThrowableProxy()); + assertEquals(exception.getClass().getName(), event.getThrowableProxy().getClassName()); + } + } + } finally { + logger.detachAppender(appender); + logger.setLevel(originalLevel); + appender.stop(); + } + } +} diff --git a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/utils/ErrorHandlingUtils.java b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/utils/ErrorHandlingUtils.java index b43464112f046..eca5a74fe0bfc 100644 --- a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/utils/ErrorHandlingUtils.java +++ b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/utils/ErrorHandlingUtils.java @@ -107,49 +107,14 @@ public static TSStatus onThriftFrameOversizeException(Throwable t) { public static TSStatus onQueryException(Exception e, String operation, TSStatusCode statusCode) { TSStatus status = tryCatchQueryException(e); if (status != null) { - // ignore logging sg not ready exception - if (status.getCode() != TSStatusCode.STORAGE_ENGINE_NOT_READY.getStatusCode()) { - String message = - String.format( - DataNodeMiscMessages - .EXCEPTION_STATUS_CODE_ARG_QUERY_STATEMENT_ARG_FAILED_BECAUSE_ARG_3BC781BF, - status.getCode(), - operation, - status.getMessage()); - if (status.getCode() == TSStatusCode.SQL_PARSE_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.SEMANTIC_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.NO_PERMISSION.getStatusCode() - || (status.getCode() >= TSStatusCode.LBAC_ACCESS_DENIED.getStatusCode() - && status.getCode() <= TSStatusCode.INVALID_LABEL_VALUE.getStatusCode()) - || status.getCode() == TSStatusCode.ILLEGAL_PATH.getStatusCode() - || status.getCode() == TSStatusCode.NUMERIC_VALUE_OUT_OF_RANGE.getStatusCode() - || status.getCode() == TSStatusCode.DIVISION_BY_ZERO.getStatusCode() - || status.getCode() == TSStatusCode.DATE_OUT_OF_RANGE.getStatusCode() - || status.getCode() == TSStatusCode.TABLE_NOT_EXISTS.getStatusCode() - || status.getCode() == TSStatusCode.TABLE_ALREADY_EXISTS.getStatusCode() - || status.getCode() == TSStatusCode.COLUMN_NOT_EXISTS.getStatusCode() - || status.getCode() == TSStatusCode.COLUMN_ALREADY_EXISTS.getStatusCode() - || status.getCode() == TSStatusCode.UDF_LOAD_CLASS_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.PLAN_FAILED_NETWORK_PARTITION.getStatusCode() - || status.getCode() == TSStatusCode.SYNC_CONNECTION_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.NO_AVAILABLE_REPLICA.getStatusCode() - || status.getCode() == TSStatusCode.CANNOT_FETCH_FI_STATE.getStatusCode() - || status.getCode() == TSStatusCode.QUERY_EXECUTION_MEMORY_NOT_ENOUGH.getStatusCode() - || status.getCode() == TSStatusCode.EXECUTE_UDF_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.TEMPLATE_INCOMPATIBLE.getStatusCode() - || status.getCode() == TSStatusCode.PATH_ALREADY_EXIST.getStatusCode() - || status.getCode() == TSStatusCode.PIPE_NOT_EXIST_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.QUERY_TIMEOUT.getStatusCode() - || status.getCode() == TSStatusCode.CANNOT_READ_TSFILE.getStatusCode() - || status.getCode() == TSStatusCode.COPY_TO_WRITE_ERROR.getStatusCode() - || status.getCode() == TSStatusCode.METADATA_LEASE_FENCED.getStatusCode() - || status.getCode() - == TSStatusCode.METADATA_LEASE_FENCED_RETRY_REQUIRED.getStatusCode()) { - LOGGER.info(message); - } else { - LOGGER.warn(message, e); - } - } + String message = + String.format( + DataNodeMiscMessages + .EXCEPTION_STATUS_CODE_ARG_QUERY_STATEMENT_ARG_FAILED_BECAUSE_ARG_3BC781BF, + status.getCode(), + operation, + status.getMessage()); + logQueryException(LOGGER, message, status.getCode(), e); status.setNeedRetry(needRetry(status)); return status; } else { @@ -157,6 +122,46 @@ public static TSStatus onQueryException(Exception e, String operation, TSStatusC } } + /** Logs expected query errors without stack traces and retains traces for unexpected errors. */ + public static void logQueryException(Logger logger, String message, int statusCode, Exception e) { + // ignore logging sg not ready exception + if (statusCode == TSStatusCode.STORAGE_ENGINE_NOT_READY.getStatusCode()) { + return; + } + if (statusCode == TSStatusCode.SQL_PARSE_ERROR.getStatusCode() + || statusCode == TSStatusCode.SEMANTIC_ERROR.getStatusCode() + || statusCode == TSStatusCode.NO_PERMISSION.getStatusCode() + || (statusCode >= TSStatusCode.LBAC_ACCESS_DENIED.getStatusCode() + && statusCode <= TSStatusCode.INVALID_LABEL_VALUE.getStatusCode()) + || statusCode == TSStatusCode.ILLEGAL_PATH.getStatusCode() + || statusCode == TSStatusCode.NUMERIC_VALUE_OUT_OF_RANGE.getStatusCode() + || statusCode == TSStatusCode.DIVISION_BY_ZERO.getStatusCode() + || statusCode == TSStatusCode.DATE_OUT_OF_RANGE.getStatusCode() + || statusCode == TSStatusCode.TABLE_NOT_EXISTS.getStatusCode() + || statusCode == TSStatusCode.TABLE_ALREADY_EXISTS.getStatusCode() + || statusCode == TSStatusCode.COLUMN_NOT_EXISTS.getStatusCode() + || statusCode == TSStatusCode.COLUMN_ALREADY_EXISTS.getStatusCode() + || statusCode == TSStatusCode.UDF_LOAD_CLASS_ERROR.getStatusCode() + || statusCode == TSStatusCode.PLAN_FAILED_NETWORK_PARTITION.getStatusCode() + || statusCode == TSStatusCode.SYNC_CONNECTION_ERROR.getStatusCode() + || statusCode == TSStatusCode.NO_AVAILABLE_REPLICA.getStatusCode() + || statusCode == TSStatusCode.CANNOT_FETCH_FI_STATE.getStatusCode() + || statusCode == TSStatusCode.QUERY_EXECUTION_MEMORY_NOT_ENOUGH.getStatusCode() + || statusCode == TSStatusCode.EXECUTE_UDF_ERROR.getStatusCode() + || statusCode == TSStatusCode.TEMPLATE_INCOMPATIBLE.getStatusCode() + || statusCode == TSStatusCode.PATH_ALREADY_EXIST.getStatusCode() + || statusCode == TSStatusCode.PIPE_NOT_EXIST_ERROR.getStatusCode() + || statusCode == TSStatusCode.QUERY_TIMEOUT.getStatusCode() + || statusCode == TSStatusCode.CANNOT_READ_TSFILE.getStatusCode() + || statusCode == TSStatusCode.COPY_TO_WRITE_ERROR.getStatusCode() + || statusCode == TSStatusCode.METADATA_LEASE_FENCED.getStatusCode() + || statusCode == TSStatusCode.METADATA_LEASE_FENCED_RETRY_REQUIRED.getStatusCode()) { + logger.info(message); + } else { + logger.warn(message, e); + } + } + public static TSStatus onQueryException(Exception e, String operation) { return onQueryException(e, operation, TSStatusCode.INTERNAL_SERVER_ERROR); }