This is an automated email from the ASF dual-hosted git repository.
morningman pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-doris.git
The following commit(s) were added to refs/heads/master by this push:
new df2c756 [improvement](log) Add query id info in error log for easy
tracking (#7975)
df2c756 is described below
commit df2c7563b08e94801daeb4370a1627886dbc3d34
Author: Mingyu Chen <morningman....@gmail.com>
AuthorDate: Wed Feb 9 13:07:28 2022 +0800
[improvement](log) Add query id info in error log for easy tracking (#7975)
This PR #7936 change some FE log level to debug, so that when error
happens, it is not easy to find out
which SQL cause the error.
So I add stmt id and query id in error log, so that user can use these
identifiers to find SQL in fe.audit.log
---
.../java/org/apache/doris/analysis/QueryStmt.java | 78 ++++++++++++++--------
.../org/apache/doris/mysql/nio/AcceptListener.java | 3 +-
.../java/org/apache/doris/qe/ConnectContext.java | 5 ++
.../java/org/apache/doris/qe/StmtExecutor.java | 18 ++---
.../org/apache/doris/planner/QueryPlanTest.java | 36 +++++++---
5 files changed, 96 insertions(+), 44 deletions(-)
diff --git a/fe/fe-core/src/main/java/org/apache/doris/analysis/QueryStmt.java
b/fe/fe-core/src/main/java/org/apache/doris/analysis/QueryStmt.java
index db0abfd..4888ab7 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/analysis/QueryStmt.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/analysis/QueryStmt.java
@@ -23,11 +23,14 @@ import org.apache.doris.common.ErrorCode;
import org.apache.doris.common.ErrorReport;
import org.apache.doris.common.UserException;
import org.apache.doris.rewrite.ExprRewriter;
+
import com.google.common.base.Preconditions;
import com.google.common.collect.Lists;
import com.google.common.collect.Sets;
+
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
+
import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
@@ -177,8 +180,8 @@ public abstract class QueryStmt extends StatementBase {
private void analyzeLimit(Analyzer analyzer) throws AnalysisException {
// TODO chenhao
if (limitElement.getOffset() > 0 && !hasOrderByClause()) {
- throw new AnalysisException("OFFSET requires an ORDER BY clause: " +
- limitElement.toSql().trim());
+ throw new AnalysisException("OFFSET requires an ORDER BY clause: "
+
+ limitElement.toSql().trim());
}
limitElement.analyze(analyzer);
}
@@ -213,7 +216,7 @@ public abstract class QueryStmt extends StatementBase {
List<TableRef> tblRefs = Lists.newArrayList();
collectTableRefs(tblRefs);
- for (TableRef tblRef: tblRefs) {
+ for (TableRef tblRef : tblRefs) {
if (absoluteRef == null && !tblRef.isRelative()) absoluteRef =
tblRef;
/*if (tblRef.isCorrelated()) {
*
@@ -313,19 +316,21 @@ public abstract class QueryStmt extends StatementBase {
// are ignored.
if (!hasLimit() && !hasOffset() && (!analyzer.isRootAnalyzer() ||
fromInsert)) {
evaluateOrderBy = false;
- // Return a warning that the order by was ignored.
- StringBuilder strBuilder = new StringBuilder();
- strBuilder.append("Ignoring ORDER BY clause without LIMIT or
OFFSET: ");
- strBuilder.append("ORDER BY ");
- strBuilder.append(orderByElements.get(0).toSql());
- for (int i = 1; i < orderByElements.size(); ++i) {
- strBuilder.append(", ").append(orderByElements.get(i).toSql());
+ if (LOG.isDebugEnabled()) {
+ // Return a warning that the order by was ignored.
+ StringBuilder strBuilder = new StringBuilder();
+ strBuilder.append("Ignoring ORDER BY clause without LIMIT or
OFFSET: ");
+ strBuilder.append("ORDER BY ");
+ strBuilder.append(orderByElements.get(0).toSql());
+ for (int i = 1; i < orderByElements.size(); ++i) {
+ strBuilder.append(",
").append(orderByElements.get(i).toSql());
+ }
+ strBuilder.append(".\nAn ORDER BY appearing in a view,
subquery, union operand, ");
+ strBuilder.append("or an insert/ctas statement has no effect
on the query result ");
+ strBuilder.append("unless a LIMIT and/or OFFSET is used in
conjunction ");
+ strBuilder.append("with the ORDER BY.");
+ LOG.debug(strBuilder.toString());
}
- strBuilder.append(".\nAn ORDER BY appearing in a view, subquery,
union operand, ");
- strBuilder.append("or an insert/ctas statement has no effect on
the query result ");
- strBuilder.append("unless a LIMIT and/or OFFSET is used in
conjunction ");
- strBuilder.append("with the ORDER BY.");
- LOG.info(strBuilder.toString());
} else {
evaluateOrderBy = true;
}
@@ -378,7 +383,7 @@ public abstract class QueryStmt extends StatementBase {
* exprs is an ambiguous alias.
*/
protected Expr getFirstAmbiguousAlias(List<Expr> exprs) {
- for (Expr exp: exprs) {
+ for (Expr exp : exprs) {
if (ambiguousAliasList.contains(exp)) return exp;
}
return null;
@@ -453,13 +458,15 @@ public abstract class QueryStmt extends StatementBase {
* collect all exprs of a QueryStmt to a map
* @param exprMap
*/
- public void collectExprs(Map<String, Expr> exprMap) {}
+ public void collectExprs(Map<String, Expr> exprMap) {
+ }
/**
* put all rewritten exprs back to the ori QueryStmt
* @param rewrittenExprMap
*/
- public void putBackExprs(Map<String, Expr> rewrittenExprMap) {}
+ public void putBackExprs(Map<String, Expr> rewrittenExprMap) {
+ }
@Override
@@ -551,14 +558,29 @@ public abstract class QueryStmt extends StatementBase {
orderByElements = null;
}
- public void setWithClause(WithClause withClause) { this.withClause_ =
withClause; }
- public boolean hasWithClause() { return withClause_ != null; }
- public WithClause getWithClause() { return withClause_; }
+ public void setWithClause(WithClause withClause) {
+ this.withClause_ = withClause;
+ }
+
+ public boolean hasWithClause() {
+ return withClause_ != null;
+ }
+
+ public WithClause getWithClause() {
+ return withClause_;
+ }
+
public boolean hasOrderByClause() {
return orderByElements != null;
}
- public boolean hasLimit() { return limitElement != null &&
limitElement.hasLimit(); }
- public boolean hasOffset() { return limitElement != null &&
limitElement.hasOffset(); }
+
+ public boolean hasLimit() {
+ return limitElement != null && limitElement.hasLimit();
+ }
+
+ public boolean hasOffset() {
+ return limitElement != null && limitElement.hasOffset();
+ }
public long getLimit() {
return limitElement.getLimit();
@@ -601,7 +623,11 @@ public abstract class QueryStmt extends StatementBase {
public SortInfo getSortInfo() {
return sortInfo;
}
- public boolean evaluateOrderBy() { return evaluateOrderBy; }
+
+ public boolean evaluateOrderBy() {
+ return evaluateOrderBy;
+ }
+
public ArrayList<Expr> getResultExprs() {
return resultExprs;
}
@@ -650,7 +676,7 @@ public abstract class QueryStmt extends StatementBase {
*/
protected void materializeSlots(Analyzer analyzer, List<Expr> exprs) {
List<SlotId> slotIds = Lists.newArrayList();
- for (Expr e: exprs) {
+ for (Expr e : exprs) {
e.getIds(null, slotIds);
}
analyzer.getDescTbl().markSlotsMaterialized(slotIds);
@@ -665,7 +691,7 @@ public abstract class QueryStmt extends StatementBase {
if (orderByElements == null) return null;
ArrayList<OrderByElement> result =
Lists.newArrayListWithCapacity(orderByElements.size());
- for (OrderByElement o: orderByElements) result.add(o.clone());
+ for (OrderByElement o : orderByElements) result.add(o.clone());
return result;
}
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/mysql/nio/AcceptListener.java
b/fe/fe-core/src/main/java/org/apache/doris/mysql/nio/AcceptListener.java
index 6acab7e..a7fd484 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/mysql/nio/AcceptListener.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/nio/AcceptListener.java
@@ -22,6 +22,7 @@ import org.apache.doris.mysql.MysqlProto;
import org.apache.doris.qe.ConnectContext;
import org.apache.doris.qe.ConnectProcessor;
import org.apache.doris.qe.ConnectScheduler;
+
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.xnio.ChannelListener;
@@ -48,7 +49,7 @@ public class AcceptListener implements
ChannelListener<AcceptingChannel<StreamCo
if (connection == null) {
return;
}
- LOG.info("Connection established. remote={}",
connection.getPeerAddress());
+ LOG.debug("Connection established. remote={}",
connection.getPeerAddress());
// connection has been established, so need to call
context.cleanup()
// if exception happens.
NConnectContext context = new NConnectContext(connection);
diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/ConnectContext.java
b/fe/fe-core/src/main/java/org/apache/doris/qe/ConnectContext.java
index 4afcabc..d24989c 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/qe/ConnectContext.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/qe/ConnectContext.java
@@ -22,6 +22,7 @@ import org.apache.doris.catalog.Catalog;
import org.apache.doris.catalog.Database;
import org.apache.doris.cluster.ClusterNamespace;
import org.apache.doris.common.UserException;
+import org.apache.doris.common.util.DebugUtil;
import org.apache.doris.mysql.MysqlCapability;
import org.apache.doris.mysql.MysqlChannel;
import org.apache.doris.mysql.MysqlCommand;
@@ -539,4 +540,8 @@ public class ConnectContext {
return row;
}
}
+
+ public String getQueryIdentifier() {
+ return "stmt[" + stmtId + ", " + DebugUtil.printId(queryId) + "]";
+ }
}
diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
index 0bad23f..5b4be01 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
@@ -364,7 +364,7 @@ public class StmtExecutor implements ProfileWriter {
if (scanNode instanceof OlapScanNode) {
OlapScanNode olapScanNode = (OlapScanNode)
scanNode;
Catalog.getCurrentCatalog().getSqlBlockRuleMgr().checkLimitaions(olapScanNode.getSelectedPartitionNum().longValue(),
- olapScanNode.getSelectedTabletsNum(),
olapScanNode.getCardinality(), analyzer.getQualifiedUser());
+ olapScanNode.getSelectedTabletsNum(),
olapScanNode.getCardinality(), analyzer.getQualifiedUser());
}
}
}
@@ -439,18 +439,18 @@ public class StmtExecutor implements ProfileWriter {
context.getState().setError(ErrorCode.ERR_NOT_SUPPORTED_YET,
"Do not support this query.");
}
} catch (IOException e) {
- LOG.warn("execute IOException ", e);
+ LOG.warn("execute IOException. {}", context.getQueryIdentifier(),
e);
// the exception happens when interact with client
// this exception shows the connection is gone
context.getState().setError(ErrorCode.ERR_UNKNOWN_ERROR,
e.getMessage());
throw e;
} catch (UserException e) {
// analysis exception only print message, not print the stack
- LOG.warn("execute Exception. {}", e.getMessage());
+ LOG.warn("execute Exception. {}, {}",
context.getQueryIdentifier(), e.getMessage());
context.getState().setError(e.getMysqlErrorCode(), e.getMessage());
context.getState().setErrType(QueryState.ErrType.ANALYSIS_ERR);
} catch (Exception e) {
- LOG.warn("execute Exception", e);
+ LOG.warn("execute Exception. {}", context.getQueryIdentifier(), e);
context.getState().setError(ErrorCode.ERR_UNKNOWN_ERROR,
e.getClass().getSimpleName() + ", msg: " + e.getMessage());
if (parsedStmt instanceof KillStmt) {
@@ -466,7 +466,7 @@ public class StmtExecutor implements ProfileWriter {
sessionVariable.setIsSingleSetVar(false);
sessionVariable.clearSessionOriginValue();
} catch (DdlException e) {
- LOG.warn("failed to revert Session value.", e);
+ LOG.warn("failed to revert Session value. {}",
context.getQueryIdentifier(), e);
context.getState().setError(e.getMysqlErrorCode(),
e.getMessage());
}
if (!context.isTxnModel() && parsedStmt instanceof InsertStmt) {
@@ -480,7 +480,7 @@ public class StmtExecutor implements ProfileWriter {
insertStmt.getDbObj().getId(),
insertStmt.getTransactionId(),
(errMsg == null ? "unknown reason" : errMsg));
} catch (Exception abortTxnException) {
- LOG.warn("errors when abort txn", abortTxnException);
+ LOG.warn("errors when abort txn. {}",
context.getQueryIdentifier(), abortTxnException);
}
}
}
@@ -580,7 +580,7 @@ public class StmtExecutor implements ProfileWriter {
} catch (UserException e) {
throw e;
} catch (Exception e) {
- LOG.warn("Analyze failed because ", e);
+ LOG.warn("Analyze failed. {}", context.getQueryIdentifier(),
e);
throw new AnalysisException("Unexpected exception: " +
e.getMessage());
} finally {
MetaLockUtils.readUnlockTables(tables);
@@ -591,7 +591,7 @@ public class StmtExecutor implements ProfileWriter {
} catch (UserException e) {
throw e;
} catch (Exception e) {
- LOG.warn("Analyze failed because ", e);
+ LOG.warn("Analyze failed. {}", context.getQueryIdentifier(),
e);
throw new AnalysisException("Unexpected exception: " +
e.getMessage());
}
}
@@ -678,7 +678,7 @@ public class StmtExecutor implements ProfileWriter {
}
if (explainOptions != null)
parsedStmt.setIsExplain(explainOptions);
}
-
+
if (parsedStmt instanceof InsertStmt && parsedStmt.isExplain()) {
if (ConnectContext.get() != null &&
ConnectContext.get().getExecutor() != null &&
diff --git
a/fe/fe-core/src/test/java/org/apache/doris/planner/QueryPlanTest.java
b/fe/fe-core/src/test/java/org/apache/doris/planner/QueryPlanTest.java
index d4cfc77..9ef045c 100644
--- a/fe/fe-core/src/test/java/org/apache/doris/planner/QueryPlanTest.java
+++ b/fe/fe-core/src/test/java/org/apache/doris/planner/QueryPlanTest.java
@@ -38,7 +38,6 @@ import org.apache.doris.catalog.Partition;
import org.apache.doris.catalog.Replica;
import org.apache.doris.catalog.Tablet;
import org.apache.doris.catalog.Type;
-import org.apache.doris.common.AnalysisException;
import org.apache.doris.common.Config;
import org.apache.doris.common.FeConstants;
import org.apache.doris.common.jmockit.Deencapsulation;
@@ -55,6 +54,7 @@ import org.apache.commons.lang3.StringUtils;
import org.junit.AfterClass;
import org.junit.Assert;
import org.junit.BeforeClass;
+import org.junit.Ignore;
import org.junit.Test;
import java.io.File;
@@ -392,7 +392,7 @@ public class QueryPlanTest {
"\"driver\" = \"Oracle Driver\",\n" +
"\"odbc_type\" = \"mysql\"\n" +
");");
-
+
createTable("create table test.tbl_int_date (" +
"`date` datetime NULL," +
"`day` date NULL," +
@@ -422,6 +422,7 @@ public class QueryPlanTest {
CreateTableStmt createTableStmt = (CreateTableStmt)
UtFrameUtils.parseAndAnalyzeStmt(sql, connectContext);
Catalog.getCurrentCatalog().createTable(createTableStmt);
}
+
private static void createView(String sql) throws Exception {
CreateViewStmt createViewStmt = (CreateViewStmt)
UtFrameUtils.parseAndAnalyzeStmt(sql, connectContext);
Catalog.getCurrentCatalog().createView(createViewStmt);
@@ -597,7 +598,7 @@ public class QueryPlanTest {
@Test
public void testMultiStmts() throws Exception {
String sql = "SHOW VARIABLES LIKE 'lower_case_%'; SHOW VARIABLES LIKE
'sql_mode'";
- List<StatementBase>stmts = UtFrameUtils.parseAndAnalyzeStmts(sql,
connectContext);
+ List<StatementBase> stmts = UtFrameUtils.parseAndAnalyzeStmts(sql,
connectContext);
Assert.assertEquals(2, stmts.size());
sql = "SHOW VARIABLES LIKE 'lower_case_%';;;";
@@ -670,7 +671,7 @@ public class QueryPlanTest {
String createSchemaSql = "create schema if not exists test";
String createDbSql = "create database if not exists test";
CreateDbStmt createSchemaStmt = (CreateDbStmt)
UtFrameUtils.parseAndAnalyzeStmt(createSchemaSql, connectContext);
- CreateDbStmt createDbStmt = (CreateDbStmt)
UtFrameUtils.parseAndAnalyzeStmt(createDbSql, connectContext);
+ CreateDbStmt createDbStmt = (CreateDbStmt)
UtFrameUtils.parseAndAnalyzeStmt(createDbSql, connectContext);
Assert.assertEquals(createDbStmt.toSql(), createSchemaStmt.toSql());
}
@@ -1505,7 +1506,7 @@ public class QueryPlanTest {
sqls.add("explain select * from baseall join bigtable as b where 1 =
2");
sqls.add("explain select * from baseall join bigtable as b on null =
2");
- for (String sql: sqls) {
+ for (String sql : sqls) {
String explainString =
UtFrameUtils.getSQLPlanOrErrorMsg(connectContext, sql);
Assert.assertTrue(explainString.contains(emptyNode));
Assert.assertFalse(explainString.contains(denseRank));
@@ -1714,7 +1715,7 @@ public class QueryPlanTest {
sql = "select day from tbl_int_date where day = 2020-10-30";
explainString = UtFrameUtils.getSQLPlanOrErrorMsg(connectContext,
"EXPLAIN " + sql);
Assert.assertTrue(explainString.contains("Incorrect datetime value:
1980 in expression: `day` = 1980"));
- //invalid date
+ //invalid date
sql = "select day from tbl_int_date where day = 10-30";
explainString = UtFrameUtils.getSQLPlanOrErrorMsg(connectContext,
"EXPLAIN " + sql);
Assert.assertTrue(explainString.contains("Incorrect datetime value:
-20 in expression: `day` = -20"));
@@ -1785,7 +1786,7 @@ public class QueryPlanTest {
}
@Test
- public void testNullColumnViewOrderBy() throws Exception{
+ public void testNullColumnViewOrderBy() throws Exception {
FeConstants.runningUnitTest = true;
connectContext.setDatabase("default_cluster:test");
String sql = "select * from tbl_null_column_view where add_column is
not null;";
@@ -1876,7 +1877,7 @@ public class QueryPlanTest {
String explainStr = UtFrameUtils.getSQLPlanOrErrorMsg(connectContext,
"EXPLAIN " + sql);
Assert.assertTrue(explainStr.contains("PREDICATES: `date` >=
'2021-10-07 00:00:00', `date` <= '2021-10-11 00:00:00'"));
}
-
+
// Fix: issue-#7929
@Test
public void testEmptyNodeWithOuterJoinAndAnalyticFunction() throws
Exception {
@@ -1912,7 +1913,26 @@ public class QueryPlanTest {
String explainStr = UtFrameUtils.getSQLPlanOrErrorMsg(connectContext,
sql, true);
Assert.assertTrue(explainStr.contains("4:EMPTYSET"));
Assert.assertTrue(explainStr.contains("tuple ids: 0 1 5"));
+ }
+ @Ignore
+ // Open it after fixing issue #7971
+ public void testGroupingSetOutOfBoundError() throws Exception {
+ String createDbStmtStr = "create database issue1111;";
+ CreateDbStmt createDbStmt = (CreateDbStmt)
UtFrameUtils.parseAndAnalyzeStmt(createDbStmtStr, connectContext);
+ Catalog.getCurrentCatalog().createDb(createDbStmt);
+ createTable("CREATE TABLE issue1111.`test1` (\n" +
+ " `k1` tinyint(4) NULL COMMENT \"\",\n" +
+ " `k2` smallint(6) NULL COMMENT \"\"\n" +
+ ") ENGINE=OLAP\n" +
+ "COMMENT \"OLAP\"\n" +
+ "DISTRIBUTED BY HASH(`k1`) BUCKETS 1\n" +
+ "PROPERTIES (\n" +
+ "\"replication_allocation\" = \"tag.location.default: 1\"\n" +
+ ");");
+ String sql = "SELECT k1 ,GROUPING(k2) FROM issue1111.test1 GROUP BY
CUBE (k1) ORDER BY k1";
+ String explainStr = UtFrameUtils.getSQLPlanOrErrorMsg(connectContext,
sql, true);
+ System.out.println(explainStr);
}
// --begin-- implicit cast in explain verbose
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@doris.apache.org
For additional commands, e-mail: commits-h...@doris.apache.org
