From 95a50f55d3abad8bf628f9876d9d0a00c716e64a Mon Sep 17 00:00:00 2001 From: Richard Antal Date: Sun, 25 Apr 2021 10:14:11 +0200 Subject: [PATCH 1/3] PHOENIX-6456 Support query logging for DDL and DML Change-Id: I0f0a39293500201c7a27a8fd8686799fb1668221 --- .../phoenix/jdbc/PhoenixConnection.java | 7 ++ .../phoenix/jdbc/PhoenixEmbeddedDriver.java | 2 +- .../jdbc/PhoenixPreparedStatement.java | 4 +- .../apache/phoenix/jdbc/PhoenixStatement.java | 100 +++++++++++++----- .../log/QueryLogDetailsWorkHandler.java | 55 ++++++++++ .../org/apache/phoenix/log/QueryLogger.java | 25 +++++ .../phoenix/log/QueryLoggerDisruptor.java | 25 ++++- .../apache/phoenix/log/TableLogWriter.java | 4 + .../apache/phoenix/query/QueryServices.java | 2 + .../phoenix/query/QueryServicesOptions.java | 2 + 10 files changed, 195 insertions(+), 31 deletions(-) create mode 100644 phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsWorkHandler.java diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java index dab4c6ae754..74aefbe504b 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java @@ -172,6 +172,7 @@ public class PhoenixConnection implements Connection, MetaDataMutated, SQLClosea private TableResultIteratorFactory tableResultIteratorFactory; private boolean isRunningUpgrade; private LogLevel logLevel; + private LogLevel auditLogLevel; private Double logSamplingRate; private String sourceOfOperation; @@ -381,6 +382,8 @@ public boolean prune(PFunction function) { }; this.logLevel= LogLevel.valueOf(this.services.getProps().get(QueryServices.LOG_LEVEL, QueryServicesOptions.DEFAULT_LOGGING_LEVEL)); + this.auditLogLevel= LogLevel.valueOf(this.services.getProps().get(QueryServices.AUDIT_LOG_LEVEL, + QueryServicesOptions.DEFAULT_AUDIT_LOGGING_LEVEL)); this.isRequestLevelMetricsEnabled = JDBCUtil.isCollectingRequestLevelMetricsEnabled(url, info, this.services.getProps()); this.mutationState = mutationState == null ? newMutationState(maxSize, @@ -1358,6 +1361,10 @@ public void setRunningUpgrade(boolean isRunningUpgrade) { public LogLevel getLogLevel(){ return this.logLevel; } + + public LogLevel getAuditLogLevel(){ + return this.auditLogLevel; + } public Double getLogSamplingRate(){ return this.logSamplingRate; diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixEmbeddedDriver.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixEmbeddedDriver.java index 989475e3e2f..27702c92bee 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixEmbeddedDriver.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixEmbeddedDriver.java @@ -349,7 +349,7 @@ public ConnectionInfo normalize(ReadOnlyProps props, Properties info) throws SQL } if(principal == null){ if (!isConnectionless) { - principal = props.get(QueryServices.HBASE_CLIENT_PRINCIPAL); + principal = props.get(QueryServices.HBASE_CLIENT_PRINCIPAL); } } if(keytab == null){ diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java index b54efc8408e..e1bbbb44876 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java @@ -170,7 +170,7 @@ boolean execute(boolean batched) throws SQLException { .build().buildException(); } if (statement.getOperation().isMutation()) { - executeMutation(statement); + executeMutation(statement, createQueryLogger(statement,query)); return false; } executeQuery(statement, createQueryLogger(statement,query)); @@ -203,7 +203,7 @@ public int executeUpdate() throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - return executeMutation(statement); + return executeMutation(statement, createQueryLogger(statement,query)); } public QueryPlan optimizeQuery() throws SQLException { diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java index 9be11d2ec1b..5663fea6114 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java @@ -379,12 +379,37 @@ public PhoenixResultSet call() throws SQLException { throw new IllegalStateException(); // Can't happen as Throwables.propagate() always throws } } - - protected int executeMutation(final CompilableStatement stmt) throws SQLException { - return executeMutation(stmt, true); + + public String getTargetForAudit(CompilableStatement stmt) { + String target = null; + try { + if (stmt instanceof ExecutableUpsertStatement) { + return ((ExecutableUpsertStatement) stmt).getTable().getName().toString(); + } else if (stmt instanceof ExecutableDeleteStatement) { + return ((ExecutableDeleteStatement) stmt).getTable().getName().toString(); + } else if (stmt instanceof ExecutableCreateTableStatement) { + target = ((ExecutableCreateTableStatement)stmt).getTableName().toString(); + } else if (stmt instanceof ExecutableDropTableStatement) { + target = ((ExecutableDropTableStatement)stmt).getTableName().toString(); + } else if (stmt instanceof ExecutableAddColumnStatement) { + target = ((ExecutableAddColumnStatement)stmt).getTable().getName().toString(); + } else if (stmt instanceof ExecutableCreateSchemaStatement) { + return ((ExecutableCreateSchemaStatement) stmt).getSchemaName(); + } else if (stmt instanceof ExecutableDropSchemaStatement) { + target = ((ExecutableDropSchemaStatement)stmt).getSchemaName(); + } + } catch (Exception e) { + target = stmt.getClass().getName(); + } + return target; } - private int executeMutation(final CompilableStatement stmt, final boolean doRetryOnMetaNotFoundError) throws SQLException { + + protected int executeMutation(final CompilableStatement stmt, final QueryLogger queryLogger) throws SQLException { + return executeMutation(stmt, true, queryLogger); + } + + private int executeMutation(final CompilableStatement stmt, final boolean doRetryOnMetaNotFoundError, final QueryLogger queryLogger) throws SQLException { if (connection.isReadOnly()) { throw new SQLExceptionInfo.Builder( SQLExceptionCode.READ_ONLY_CONNECTION). @@ -425,6 +450,13 @@ public Integer call() throws SQLException { setLastUpdateCount(lastUpdateCount); setLastUpdateOperation(stmt.getOperation()); connection.incrementStatementExecutionCounter(); + if(queryLogger.isAuditLoggingEnabled()) { + queryLogger.log(QueryLogInfo.TABLE_NAME_I, getTargetForAudit(stmt)); + queryLogger.log(QueryLogInfo.QUERY_STATUS_I, QueryStatus.COMPLETED.toString()); + queryLogger.log(QueryLogInfo.NO_OF_RESULTS_ITERATED_I, lastUpdateCount); + queryLogger.syncAudit(null, null); + } + return lastUpdateCount; } //Force update cache and retry if meta not found error occurs @@ -435,7 +467,7 @@ public Integer call() throws SQLException { } if (new MetaDataClient(connection).updateCache(connection.getTenantId(), e.getSchemaName(), e.getTableName(), true).wasUpdated()) { - return executeMutation(stmt, false); + return executeMutation(stmt, false, queryLogger); } } throw e; @@ -451,6 +483,12 @@ public Integer call() throws SQLException { }, PhoenixContextExecutor.inContext(), Tracing.withTracing(connection, this.toString())); } catch (Exception e) { + if(queryLogger.isAuditLoggingEnabled()) { + queryLogger.log(QueryLogInfo.TABLE_NAME_I, getTargetForAudit(stmt)); + queryLogger.log(QueryLogInfo.EXCEPTION_TRACE_I, Throwables.getStackTraceAsString(e)); + queryLogger.log(QueryLogInfo.QUERY_STATUS_I, QueryStatus.FAILED.toString()); + queryLogger.syncAudit(null, null); + } Throwables.propagateIfInstanceOf(e, SQLException.class); Throwables.propagate(e); throw new IllegalStateException(); // Can't happen as Throwables.propagate() always throws @@ -1855,25 +1893,39 @@ public MutationPlan compileMutation(String sql) throws SQLException { return compileMutation(stmt, sql); } - public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throws SQLException { - if (connection.getLogLevel() == LogLevel.OFF) { - return QueryLogger.NO_OP_INSTANCE; - } - - boolean isSystemTable = false; - if(stmt instanceof ExecutableSelectStatement) { + public boolean checkIgnoreQueryAudit(CompilableStatement stmt) { + boolean needIgnore = false; + TableName tableName = null; + if (stmt instanceof ExecutableSelectStatement) { TableNode from = ((ExecutableSelectStatement)stmt).getFrom(); if(from instanceof NamedTableNode) { - String schemaName = ((NamedTableNode)from).getName().getSchemaName(); - if(schemaName == null) { - schemaName=connection.getSchema(); - } - if (PhoenixDatabaseMetaData.SYSTEM_CATALOG_SCHEMA.equals(schemaName)) { - isSystemTable = true; - } + tableName = ((NamedTableNode)from).getName(); } + } else if (stmt instanceof ExecutableUpsertStatement) { + tableName = ((ExecutableUpsertStatement)stmt).getTable().getName(); + } else if (stmt instanceof ExecutableDeleteStatement) { + tableName = ((ExecutableDeleteStatement)stmt).getTable().getName(); + } else if (stmt instanceof ExecutableAddColumnStatement) { + tableName = ((ExecutableAddColumnStatement)stmt).getTable().getName(); + } + + if (tableName != null && PhoenixDatabaseMetaData.SYSTEM_CATALOG_SCHEMA + .equals(tableName.getSchemaName())) { + needIgnore = true; } - QueryLogger queryLogger = QueryLogger.getInstance(connection,isSystemTable); + + return needIgnore; + } + + public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throws SQLException { + if (connection.getLogLevel() == LogLevel.OFF && + connection.getAuditLogLevel() == LogLevel.OFF) { + return QueryLogger.NO_OP_INSTANCE; + } + + boolean isSystemTable = checkIgnoreQueryAudit(stmt); + + QueryLogger queryLogger = QueryLogger.getInstance(connection, isSystemTable); QueryLoggerUtil.logInitialDetails(queryLogger, connection.getTenantId(), connection.getQueryServices(), sql, getParameters()); return queryLogger; @@ -1890,7 +1942,7 @@ public ResultSet executeQuery(String sql) throws SQLException { if (stmt.getOperation().isMutation()) { throw new ExecuteQueryNotApplicableException(sql); } - return executeQuery(stmt,createQueryLogger(stmt,sql)); + return executeQuery(stmt, createQueryLogger(stmt, sql)); } @Override @@ -1903,7 +1955,7 @@ public int executeUpdate(String sql) throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - int updateCount = executeMutation(stmt); + int updateCount = executeMutation(stmt, createQueryLogger(stmt, sql)); flushIfNecessary(); return updateCount; } @@ -1922,12 +1974,12 @@ public boolean execute(String sql) throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - executeMutation(stmt); + executeMutation(stmt, createQueryLogger(stmt, sql)); flushIfNecessary(); return false; } - executeQuery(stmt,createQueryLogger(stmt,sql)); + executeQuery(stmt, createQueryLogger(stmt, sql)); return true; } diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsWorkHandler.java b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsWorkHandler.java new file mode 100644 index 00000000000..82d30a25e9b --- /dev/null +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsWorkHandler.java @@ -0,0 +1,55 @@ +/* + * 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.phoenix.log; + +import com.lmax.disruptor.LifecycleAware; +import com.lmax.disruptor.WorkHandler; +import org.apache.hadoop.conf.Configuration; + + +public class QueryLogDetailsWorkHandler implements WorkHandler, LifecycleAware { + + + private LogWriter logWriter; + + public QueryLogDetailsWorkHandler(Configuration configuration) { + this.logWriter = new TableLogWriter(configuration); + } + + @Override + public void onEvent(RingBufferEvent ringBufferEvent) throws Exception { + logWriter.write(ringBufferEvent); + ringBufferEvent.clear(); + } + + @Override + public void onStart() { + + } + + @Override + public void onShutdown() { + try { + if (logWriter != null) { + logWriter.close(); + } + } catch (Exception e) { + //Ignore + } + } +} \ No newline at end of file diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java index 68a4e915aec..f96172bbe6f 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java @@ -39,6 +39,7 @@ public class QueryLogger { private QueryLoggerDisruptor queryDisruptor; private String queryId; private LogLevel logLevel; + private LogLevel auditLogLevel; private Builder queryLogBuilder = ImmutableMap.builder(); private boolean isSynced; private static final Logger LOGGER = LoggerFactory.getLogger(QueryLogger.class); @@ -47,12 +48,14 @@ private QueryLogger(PhoenixConnection connection) { this.queryId = UUID.randomUUID().toString(); this.queryDisruptor = connection.getQueryServices().getQueryDisruptor(); logLevel = connection.getLogLevel(); + auditLogLevel = connection.getAuditLogLevel(); log(QueryLogInfo.QUERY_ID_I, queryId); log(QueryLogInfo.START_TIME_I, EnvironmentEdgeManager.currentTimeMillis()); } private QueryLogger() { logLevel = LogLevel.OFF; + auditLogLevel = LogLevel.OFF; } private RingBufferEventTranslator getCachedTranslator() { @@ -130,6 +133,20 @@ private boolean isLevelEnabled(LogLevel logLevel){ return this.logLevel != null && logLevel != LogLevel.OFF ? logLevel.ordinal() <= this.logLevel.ordinal() : false; } + + /** + * Is audit logging currently enabled? + * Call this method to prevent having to perform expensive operations (for example, + * String concatenation) when the audit log level is more than info. + */ + public boolean isAuditLoggingEnabled(){ + return isAuditLevelEnabled(LogLevel.INFO); + } + + private boolean isAuditLevelEnabled(LogLevel logLevel){ + return this.auditLogLevel != null && logLevel != LogLevel.OFF ? logLevel.ordinal() <= this.auditLogLevel.ordinal() + : false; + } /** * Is Info logging currently enabled? @@ -155,6 +172,14 @@ public String getQueryId() { public void sync(Map> readMetrics, Map overAllMetrics) { + syncBase(readMetrics, overAllMetrics, logLevel); + } + + public void syncAudit(Map> readMetrics, Map overAllMetrics) { + syncBase(readMetrics, overAllMetrics, LogLevel.TRACE); + } + + public void syncBase(Map> readMetrics, Map overAllMetrics, LogLevel logLevel) { if (!isSynced) { isSynced = true; final RingBufferEventTranslator translator = getCachedTranslator(); diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLoggerDisruptor.java b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLoggerDisruptor.java index 3c8f955f0aa..935b0583ccc 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLoggerDisruptor.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLoggerDisruptor.java @@ -23,7 +23,6 @@ import java.util.concurrent.Executors; import java.util.concurrent.ThreadFactory; import java.util.concurrent.TimeUnit; - import org.apache.hadoop.conf.Configuration; import org.apache.phoenix.query.QueryServices; import org.slf4j.Logger; @@ -46,6 +45,7 @@ public class QueryLoggerDisruptor implements Closeable{ private static final int RING_BUFFER_SIZE = 8 * 1024; private static final Logger LOGGER = LoggerFactory.getLogger(QueryLoggerDisruptor.class); private static final String DEFAULT_WAIT_STRATEGY = BlockingWaitStrategy.class.getName(); + private static final int DEFAULT_AUDIT_LOGGER_PROCESS_COUNT = 1; public QueryLoggerDisruptor(Configuration configuration) throws SQLException{ WaitStrategy waitStrategy; @@ -74,12 +74,29 @@ public Thread newThread(Runnable r) { final ExceptionHandler errorHandler = new QueryLoggerDefaultExceptionHandler(); disruptor.setDefaultExceptionHandler(errorHandler); - final QueryLogDetailsEventHandler[] handlers = { new QueryLogDetailsEventHandler(configuration) }; - disruptor.handleEventsWith(handlers); + /** + * if LOG_HANDLER_COUNT is 1 it will work as the previous implementation + * if LOG_HANDLER_COUNT is 2 or more then Multi Thread + */ + int handlerCount = configuration.getInt( + QueryServices.LOG_HANDLER_COUNT, DEFAULT_AUDIT_LOGGER_PROCESS_COUNT); + + if (handlerCount <= 0){ + LOGGER.error("Audit Log Handler Count must be greater than 0." + + "change to default value, input : " + handlerCount); + handlerCount = DEFAULT_AUDIT_LOGGER_PROCESS_COUNT; + } + + QueryLogDetailsWorkHandler[] workHandlers = new QueryLogDetailsWorkHandler[handlerCount]; + for (int i = 0; i < handlerCount; i++){ + workHandlers[i] = new QueryLogDetailsWorkHandler(configuration); + } + disruptor.handleEventsWithWorkerPool(workHandlers); + LOGGER.info("Starting QueryLoggerDisruptor for with ringbufferSize=" + disruptor.getRingBuffer().getBufferSize() + ", waitStrategy=" + waitStrategy.getClass().getSimpleName() + ", " + "exceptionHandler=" - + errorHandler + "..."); + + errorHandler + ", handlerCount=" + handlerCount); disruptor.start(); } diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/TableLogWriter.java b/phoenix-core/src/main/java/org/apache/phoenix/log/TableLogWriter.java index 7dd7b1718b2..966bed42a89 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/log/TableLogWriter.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/TableLogWriter.java @@ -96,6 +96,10 @@ public void write(RingBufferEvent event) throws SQLException, IOException { } } + if (connection.isReadOnly()) { + return; + } + ImmutableMap queryInfoMap = event.getQueryInfo(); for (QueryLogInfo info : QueryLogInfo.values()) { if (queryInfoMap.containsKey(info) && info.logLevel.ordinal() <= event.getConnectionLogLevel().ordinal()) { diff --git a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServices.java b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServices.java index ac9a39622f9..78f153c8027 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServices.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServices.java @@ -309,9 +309,11 @@ public interface QueryServices extends SQLCloseable { public static final String WILDCARD_QUERY_DYNAMIC_COLS_ATTRIB = "phoenix.query.wildcard.dynamicColumns"; public static final String LOG_LEVEL = "phoenix.log.level"; + public static final String AUDIT_LOG_LEVEL = "phoenix.audit.log.level"; public static final String LOG_BUFFER_SIZE = "phoenix.log.buffer.size"; public static final String LOG_BUFFER_WAIT_STRATEGY = "phoenix.log.wait.strategy"; public static final String LOG_SAMPLE_RATE = "phoenix.log.sample.rate"; + public static final String LOG_HANDLER_COUNT = "phoenix.log.handler.count"; public static final String SYSTEM_CATALOG_SPLITTABLE = "phoenix.system.catalog.splittable"; diff --git a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java index 85f932ba12c..a16eecc7888 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java @@ -361,6 +361,8 @@ public class QueryServicesOptions { public static final boolean DEFAULT_COST_BASED_OPTIMIZER_ENABLED = false; public static final boolean DEFAULT_WILDCARD_QUERY_DYNAMIC_COLS_ATTRIB = false; public static final String DEFAULT_LOGGING_LEVEL = LogLevel.OFF.name(); + public static final String DEFAULT_AUDIT_LOGGING_LEVEL = LogLevel.OFF.name(); + public static final String DEFAULT_LOG_SAMPLE_RATE = "1.0"; public static final int DEFAULT_LOG_SALT_BUCKETS = 32; public static final int DEFAULT_SALT_BUCKETS = 0; From 977739cb1c0f5c9729da63bec7a9ab3708fa6a2d Mon Sep 17 00:00:00 2001 From: Richard Antal Date: Wed, 28 Apr 2021 07:50:48 +0200 Subject: [PATCH 2/3] Cleanup based on Istvan's review Change-Id: Ieb0fed3f245a15297a34752b6a2b95f548eba396 --- .../apache/phoenix/jdbc/PhoenixStatement.java | 12 ++-- .../log/QueryLogDetailsEventHandler.java | 63 ------------------- .../phoenix/query/QueryServicesOptions.java | 1 - 3 files changed, 5 insertions(+), 71 deletions(-) delete mode 100644 phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsEventHandler.java diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java index 5663fea6114..eb693ab122f 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java @@ -1893,8 +1893,8 @@ public MutationPlan compileMutation(String sql) throws SQLException { return compileMutation(stmt, sql); } - public boolean checkIgnoreQueryAudit(CompilableStatement stmt) { - boolean needIgnore = false; + public boolean isSystemTable(CompilableStatement stmt) { + boolean systemTable = false; TableName tableName = null; if (stmt instanceof ExecutableSelectStatement) { TableNode from = ((ExecutableSelectStatement)stmt).getFrom(); @@ -1911,10 +1911,10 @@ public boolean checkIgnoreQueryAudit(CompilableStatement stmt) { if (tableName != null && PhoenixDatabaseMetaData.SYSTEM_CATALOG_SCHEMA .equals(tableName.getSchemaName())) { - needIgnore = true; + systemTable = true; } - return needIgnore; + return systemTable; } public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throws SQLException { @@ -1923,9 +1923,7 @@ public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throw return QueryLogger.NO_OP_INSTANCE; } - boolean isSystemTable = checkIgnoreQueryAudit(stmt); - - QueryLogger queryLogger = QueryLogger.getInstance(connection, isSystemTable); + QueryLogger queryLogger = QueryLogger.getInstance(connection, isSystemTable(stmt)); QueryLoggerUtil.logInitialDetails(queryLogger, connection.getTenantId(), connection.getQueryServices(), sql, getParameters()); return queryLogger; diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsEventHandler.java b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsEventHandler.java deleted file mode 100644 index ee6b2d641f4..00000000000 --- a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogDetailsEventHandler.java +++ /dev/null @@ -1,63 +0,0 @@ -/* - * 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.phoenix.log; - -import java.sql.SQLException; - -import org.apache.hadoop.conf.Configuration; - -import com.lmax.disruptor.LifecycleAware; -import com.lmax.disruptor.Sequence; -import com.lmax.disruptor.SequenceReportingEventHandler; - - -public class QueryLogDetailsEventHandler implements SequenceReportingEventHandler, LifecycleAware { - private Sequence sequenceCallback; - private LogWriter logWriter; - - public QueryLogDetailsEventHandler(Configuration configuration) throws SQLException{ - this.logWriter = new TableLogWriter(configuration); - } - - @Override - public void setSequenceCallback(final Sequence sequenceCallback) { - this.sequenceCallback = sequenceCallback; - } - - @Override - public void onEvent(final RingBufferEvent event, final long sequence, final boolean endOfBatch) throws Exception { - logWriter.write(event); - event.clear(); - } - - @Override - public void onStart() { - } - - @Override - public void onShutdown() { - try { - if (logWriter != null) { - logWriter.close(); - } - } catch (Exception e) { - //Ignore - } - } - -} diff --git a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java index a16eecc7888..ac343def68e 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/query/QueryServicesOptions.java @@ -362,7 +362,6 @@ public class QueryServicesOptions { public static final boolean DEFAULT_WILDCARD_QUERY_DYNAMIC_COLS_ATTRIB = false; public static final String DEFAULT_LOGGING_LEVEL = LogLevel.OFF.name(); public static final String DEFAULT_AUDIT_LOGGING_LEVEL = LogLevel.OFF.name(); - public static final String DEFAULT_LOG_SAMPLE_RATE = "1.0"; public static final int DEFAULT_LOG_SALT_BUCKETS = 32; public static final int DEFAULT_SALT_BUCKETS = 0; From 88b9f0f06d7632015eb4389a255f6a684040dc75 Mon Sep 17 00:00:00 2001 From: Richard Antal Date: Thu, 29 Apr 2021 17:42:44 +0200 Subject: [PATCH 3/3] Separating AuditQueryLogger + Adding test Change-Id: I3a7591c3224ebd54358f322981cde6b1d220002e --- .../phoenix/end2end/AuditLoggingIT.java | 248 ++++++++++++++++++ .../jdbc/PhoenixPreparedStatement.java | 4 +- .../apache/phoenix/jdbc/PhoenixStatement.java | 27 +- .../apache/phoenix/log/AuditQueryLogger.java | 119 +++++++++ .../org/apache/phoenix/log/QueryLogger.java | 27 +- 5 files changed, 391 insertions(+), 34 deletions(-) create mode 100644 phoenix-core/src/it/java/org/apache/phoenix/end2end/AuditLoggingIT.java create mode 100644 phoenix-core/src/main/java/org/apache/phoenix/log/AuditQueryLogger.java diff --git a/phoenix-core/src/it/java/org/apache/phoenix/end2end/AuditLoggingIT.java b/phoenix-core/src/it/java/org/apache/phoenix/end2end/AuditLoggingIT.java new file mode 100644 index 00000000000..e83ff903a71 --- /dev/null +++ b/phoenix-core/src/it/java/org/apache/phoenix/end2end/AuditLoggingIT.java @@ -0,0 +1,248 @@ +/* + * 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.phoenix.end2end; + +import org.apache.phoenix.log.LogLevel; +import org.apache.phoenix.query.QueryServices; +import org.apache.phoenix.util.PropertiesUtil; +import org.junit.Test; + +import java.sql.*; +import java.util.Properties; + +import static org.apache.phoenix.util.TestUtil.TEST_PROPERTIES; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; +import static org.junit.Assert.assertEquals; + +public class AuditLoggingIT extends ParallelStatsDisabledIT { + + @Test + public void testEmptyLogging() throws Exception { + String createqQery = "create table test1 (mykey integer not null primary key," + + " mycolumn varchar)"; + String upsertQuery = "upsert into test1 values (1,'Hello')"; + String selectQuery = "select * from test1"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST1' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + Statement stmt = conn.createStatement(); + stmt.execute(createqQery); + stmt.execute(upsertQuery); + stmt.executeQuery(selectQuery); + conn.commit(); + + ResultSet rs = stmt.executeQuery(getLogsQuery); + assertFalse(rs.next()); + } finally { + conn.close(); + } + } + + @Test + public void testLoggingSelect() throws Exception { + String createqQery = "create table test2 (mykey integer not null primary key," + + " mycolumn varchar)"; + String upsertQuery = "upsert into test2 values (1,'Hello')"; + String selectQuery = "select * from test2"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST2' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + props.setProperty(QueryServices.LOG_LEVEL, LogLevel.TRACE.name()); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + conn.createStatement().execute(createqQery); + conn.createStatement().execute(upsertQuery); + ResultSet rs = conn.createStatement().executeQuery(selectQuery); + assertTrue(rs.next()); + assertFalse(rs.next()); + rs.close(); + + ResultSet rs2 = conn.createStatement().executeQuery(getLogsQuery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), selectQuery); + assertFalse(rs2.next()); + } finally { + conn.close(); + } + } + + @Test + public void testLoggingDMLAandDDL() throws Exception { + String createqQery = "create table test3 (mykey integer not null primary key," + + " mycolumn varchar)"; + String upsertQuery = "upsert into test3 values (1,'Hello')"; + String selectQuery = "select * from test3"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST3' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + props.setProperty(QueryServices.AUDIT_LOG_LEVEL, LogLevel.INFO.name()); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + conn.createStatement().execute(createqQery); + conn.createStatement().execute(upsertQuery); + ResultSet rs = conn.createStatement().executeQuery(selectQuery); + assertTrue(rs.next()); + assertFalse(rs.next()); + rs.close(); + + ResultSet rs2 = conn.createStatement().executeQuery(getLogsQuery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), createqQery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), upsertQuery); + + assertFalse(rs2.next()); + } finally { + conn.close(); + } + } + + @Test + public void testLoggingDMLAandDDLandSelect() throws Exception { + String createqQery = "create table test4 (mykey integer not null primary key," + + " mycolumn varchar)"; + String upsertQuery = "upsert into test4 values (1,'Hello')"; + String selectQuery = "select * from test4"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST4' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + props.setProperty(QueryServices.AUDIT_LOG_LEVEL, LogLevel.INFO.name()); + props.setProperty(QueryServices.LOG_LEVEL, LogLevel.TRACE.name()); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + Statement stat = conn.createStatement(); + stat.execute(createqQery); + stat.execute(upsertQuery); + ResultSet rs = stat.executeQuery(selectQuery); + assertTrue(rs.next()); + assertFalse(rs.next()); + rs.close(); + + ResultSet rs2 = conn.createStatement().executeQuery(getLogsQuery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), createqQery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), upsertQuery); + assertTrue(rs2.next()); + assertEquals(rs2.getString(7), selectQuery); + + assertFalse(rs2.next()); + + } finally { + conn.close(); + } + } + + @Test + public void testLogginParameterizedUpsert() throws Exception { + String createqQery = "create table test5 (mykey integer not null primary key," + + " mycolumn varchar)"; + String upsertQuery = "upsert into test5 values (?, ?)"; + String selectQuery = "select * from test5"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST5' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + props.setProperty(QueryServices.AUDIT_LOG_LEVEL, LogLevel.INFO.name()); + props.setProperty(QueryServices.LOG_LEVEL, LogLevel.TRACE.name()); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + Statement stat = conn.createStatement(); + stat.execute(createqQery); + + + PreparedStatement p = conn.prepareStatement(upsertQuery); + p.setInt(1, 1); + p.setString(2, "foo"); + + p.execute(); + + p.setInt(1, 2); + p.setString(2, "bar"); + + p.execute(); + + ResultSet rs = stat.executeQuery(selectQuery); + assertTrue(rs.next()); + assertTrue(rs.next()); + assertFalse(rs.next()); + rs.close(); + + ResultSet rs2 = conn.createStatement().executeQuery(getLogsQuery); + assertTrue(rs2.next()); + assertTrue(rs2.next()); + assertEquals("1,foo", rs2.getString(13)); + assertTrue(rs2.next()); + assertEquals( "2,bar", rs2.getString(13)); + assertTrue(rs2.next()); + assertFalse(rs2.next()); + + } finally { + conn.close(); + } + } + + @Test + public void testlogSamplingRate() throws Exception { + String createqQery = "create table test6 (mykey integer not null primary key," + + " mycolumn varchar)"; + + String selectQuery = "select * from test6"; + String getLogsQuery = "select * from SYSTEM.LOG WHERE TABLE_NAME='TEST6' order by start_time"; + Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + props.setProperty(QueryServices.AUDIT_LOG_LEVEL, LogLevel.INFO.name()); + props.setProperty(QueryServices.LOG_LEVEL, LogLevel.TRACE.name()); + props.setProperty(QueryServices.LOG_SAMPLE_RATE, "0.5"); + Connection conn = DriverManager.getConnection(getUrl(), props); + conn.setAutoCommit(true); + try { + Statement stat = conn.createStatement(); + stat.execute(createqQery); + String upsertQuery; + for (int i = 0; i<100; i++) { + upsertQuery = "upsert into test6 values (" + i + ",'asd')"; + stat.execute(upsertQuery); + ResultSet rs = stat.executeQuery(selectQuery); + assertTrue(rs.next()); + rs.close(); + } + + ResultSet rs2 = conn.createStatement().executeQuery(getLogsQuery); + int numOfUpserts = 0; + int numOfSelects = 0; + while (rs2.next()) { + String query = rs2.getString(7); + if (query.equals(selectQuery)) { + numOfSelects++; + } + else if (query.contains("upsert into test6 values (")) { + numOfUpserts++; + } + } + assertEquals(numOfUpserts, 100); + assertTrue(numOfSelects > 0 && numOfSelects < 100); + System.out.println(numOfSelects); + + } finally { + conn.close(); + } + } + +} diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java index e1bbbb44876..59d8add4885 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixPreparedStatement.java @@ -170,7 +170,7 @@ boolean execute(boolean batched) throws SQLException { .build().buildException(); } if (statement.getOperation().isMutation()) { - executeMutation(statement, createQueryLogger(statement,query)); + executeMutation(statement, createAuditQueryLogger(statement,query)); return false; } executeQuery(statement, createQueryLogger(statement,query)); @@ -203,7 +203,7 @@ public int executeUpdate() throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - return executeMutation(statement, createQueryLogger(statement,query)); + return executeMutation(statement, createAuditQueryLogger(statement,query)); } public QueryPlan optimizeQuery() throws SQLException { diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java index eb693ab122f..69774b21ed6 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixStatement.java @@ -88,6 +88,7 @@ import org.apache.phoenix.iterate.MaterializedResultIterator; import org.apache.phoenix.iterate.ParallelScanGrouper; import org.apache.phoenix.iterate.ResultIterator; +import org.apache.phoenix.log.AuditQueryLogger; import org.apache.phoenix.log.LogLevel; import org.apache.phoenix.log.QueryLogInfo; import org.apache.phoenix.log.QueryLogger; @@ -405,11 +406,11 @@ public String getTargetForAudit(CompilableStatement stmt) { } - protected int executeMutation(final CompilableStatement stmt, final QueryLogger queryLogger) throws SQLException { + protected int executeMutation(final CompilableStatement stmt, final AuditQueryLogger queryLogger) throws SQLException { return executeMutation(stmt, true, queryLogger); } - private int executeMutation(final CompilableStatement stmt, final boolean doRetryOnMetaNotFoundError, final QueryLogger queryLogger) throws SQLException { + private int executeMutation(final CompilableStatement stmt, final boolean doRetryOnMetaNotFoundError, final AuditQueryLogger queryLogger) throws SQLException { if (connection.isReadOnly()) { throw new SQLExceptionInfo.Builder( SQLExceptionCode.READ_ONLY_CONNECTION). @@ -454,7 +455,7 @@ public Integer call() throws SQLException { queryLogger.log(QueryLogInfo.TABLE_NAME_I, getTargetForAudit(stmt)); queryLogger.log(QueryLogInfo.QUERY_STATUS_I, QueryStatus.COMPLETED.toString()); queryLogger.log(QueryLogInfo.NO_OF_RESULTS_ITERATED_I, lastUpdateCount); - queryLogger.syncAudit(null, null); + queryLogger.syncAudit(); } return lastUpdateCount; @@ -487,7 +488,7 @@ public Integer call() throws SQLException { queryLogger.log(QueryLogInfo.TABLE_NAME_I, getTargetForAudit(stmt)); queryLogger.log(QueryLogInfo.EXCEPTION_TRACE_I, Throwables.getStackTraceAsString(e)); queryLogger.log(QueryLogInfo.QUERY_STATUS_I, QueryStatus.FAILED.toString()); - queryLogger.syncAudit(null, null); + queryLogger.syncAudit(); } Throwables.propagateIfInstanceOf(e, SQLException.class); Throwables.propagate(e); @@ -1918,8 +1919,7 @@ public boolean isSystemTable(CompilableStatement stmt) { } public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throws SQLException { - if (connection.getLogLevel() == LogLevel.OFF && - connection.getAuditLogLevel() == LogLevel.OFF) { + if (connection.getLogLevel() == LogLevel.OFF) { return QueryLogger.NO_OP_INSTANCE; } @@ -1928,6 +1928,17 @@ public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throw connection.getQueryServices(), sql, getParameters()); return queryLogger; } + + public AuditQueryLogger createAuditQueryLogger(CompilableStatement stmt, String sql) throws SQLException { + if (connection.getAuditLogLevel() == LogLevel.OFF) { + return AuditQueryLogger.NO_OP_INSTANCE; + } + + AuditQueryLogger queryLogger = AuditQueryLogger.getInstance(connection, isSystemTable(stmt)); + QueryLoggerUtil.logInitialDetails(queryLogger, connection.getTenantId(), + connection.getQueryServices(), sql, getParameters()); + return queryLogger; + } @Override public ResultSet executeQuery(String sql) throws SQLException { @@ -1953,7 +1964,7 @@ public int executeUpdate(String sql) throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - int updateCount = executeMutation(stmt, createQueryLogger(stmt, sql)); + int updateCount = executeMutation(stmt, createAuditQueryLogger(stmt, sql)); flushIfNecessary(); return updateCount; } @@ -1972,7 +1983,7 @@ public boolean execute(String sql) throws SQLException { throw new SQLExceptionInfo.Builder(SQLExceptionCode.EXECUTE_UPDATE_WITH_NON_EMPTY_BATCH) .build().buildException(); } - executeMutation(stmt, createQueryLogger(stmt, sql)); + executeMutation(stmt, createAuditQueryLogger(stmt, sql)); flushIfNecessary(); return false; } diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/AuditQueryLogger.java b/phoenix-core/src/main/java/org/apache/phoenix/log/AuditQueryLogger.java new file mode 100644 index 00000000000..8e4fc51e881 --- /dev/null +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/AuditQueryLogger.java @@ -0,0 +1,119 @@ +/* + * 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.phoenix.log; + +import org.apache.phoenix.jdbc.PhoenixConnection; +import org.apache.phoenix.monitoring.MetricType; + +import java.util.Map; + + +/* + * Wrapper for query translator + */ +public class AuditQueryLogger extends QueryLogger { + private LogLevel auditLogLevel; + + + private AuditQueryLogger(PhoenixConnection connection) { + super(connection); + auditLogLevel = connection.getAuditLogLevel(); + + } + + private AuditQueryLogger() { + super(); + auditLogLevel = LogLevel.OFF; + } + + public static final AuditQueryLogger NO_OP_INSTANCE = new AuditQueryLogger() { + @Override + public void log(QueryLogInfo queryLogInfo, Object info) { + + } + + @Override + public boolean isDebugEnabled() { + return false; + } + + @Override + public boolean isInfoEnabled() { + return false; + } + + @Override + public void sync( + Map> readMetrics, Map overAllMetrics) { + + } + + @Override + public void syncAudit( + Map> readMetrics, Map overAllMetrics) { + + } + + @Override + public boolean isSynced(){ + return true; + } + }; + + public static AuditQueryLogger getInstance(PhoenixConnection connection, boolean isSystemTable) { + if (connection.getAuditLogLevel() == LogLevel.OFF || isSystemTable) { + return NO_OP_INSTANCE; + } + return new AuditQueryLogger(connection); + } + + + /** + * Is audit logging currently enabled? + * Call this method to prevent having to perform expensive operations (for example, + * String concatenation) when the audit log level is more than info. + */ + public boolean isAuditLoggingEnabled(){ + return isAuditLevelEnabled(LogLevel.INFO); + } + + private boolean isAuditLevelEnabled(LogLevel logLevel){ + return this.auditLogLevel != null && logLevel != LogLevel.OFF ? logLevel.ordinal() <= this.auditLogLevel.ordinal() + : false; + } + + + + public void sync(Map> readMetrics, Map overAllMetrics) { + syncBase(readMetrics, overAllMetrics, auditLogLevel); + } + + public void syncAudit() { + syncAudit(null, null); + } + + /** + * We force LogLevel.TRACE here because in QueryLogInfo the minimum LogLevel for + * TABLE_NAME_I is Debug and for BIND_PARAMETERS_I is TRACE and we would like to see + * these parameters even in INFO level when using DDL and DML operations. + */ + public void syncAudit(Map> readMetrics, Map overAllMetrics) { + syncBase(readMetrics, overAllMetrics, LogLevel.TRACE); + } + +} diff --git a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java index f96172bbe6f..b132bbd7e96 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/log/QueryLogger.java @@ -39,23 +39,20 @@ public class QueryLogger { private QueryLoggerDisruptor queryDisruptor; private String queryId; private LogLevel logLevel; - private LogLevel auditLogLevel; private Builder queryLogBuilder = ImmutableMap.builder(); private boolean isSynced; private static final Logger LOGGER = LoggerFactory.getLogger(QueryLogger.class); - private QueryLogger(PhoenixConnection connection) { + protected QueryLogger(PhoenixConnection connection) { this.queryId = UUID.randomUUID().toString(); this.queryDisruptor = connection.getQueryServices().getQueryDisruptor(); logLevel = connection.getLogLevel(); - auditLogLevel = connection.getAuditLogLevel(); log(QueryLogInfo.QUERY_ID_I, queryId); log(QueryLogInfo.START_TIME_I, EnvironmentEdgeManager.currentTimeMillis()); } - - private QueryLogger() { + + protected QueryLogger() { logLevel = LogLevel.OFF; - auditLogLevel = LogLevel.OFF; } private RingBufferEventTranslator getCachedTranslator() { @@ -133,20 +130,6 @@ private boolean isLevelEnabled(LogLevel logLevel){ return this.logLevel != null && logLevel != LogLevel.OFF ? logLevel.ordinal() <= this.logLevel.ordinal() : false; } - - /** - * Is audit logging currently enabled? - * Call this method to prevent having to perform expensive operations (for example, - * String concatenation) when the audit log level is more than info. - */ - public boolean isAuditLoggingEnabled(){ - return isAuditLevelEnabled(LogLevel.INFO); - } - - private boolean isAuditLevelEnabled(LogLevel logLevel){ - return this.auditLogLevel != null && logLevel != LogLevel.OFF ? logLevel.ordinal() <= this.auditLogLevel.ordinal() - : false; - } /** * Is Info logging currently enabled? @@ -175,10 +158,6 @@ public void sync(Map> readMetrics, Map> readMetrics, Map overAllMetrics) { - syncBase(readMetrics, overAllMetrics, LogLevel.TRACE); - } - public void syncBase(Map> readMetrics, Map overAllMetrics, LogLevel logLevel) { if (!isSynced) { isSynced = true;