Uh oh!
There was an error while loading. Please reload this page.
PHOENIX-6456 Support query logging for DDL and DML - #1210
Conversation
stoty
commented
Apr 26, 2021
💔 -1 overall
This message was automatically generated. |
| handlerCount = DEFAULT_AUDIT_LOGGER_PROCESS_COUNT; | ||
| } | ||
| if (handlerCount == 1) { |
There was a problem hiding this comment.
Can't we just use a workhandler pool with a single worker ?
I think we need not keep QueryLogDetailsEventHandler.
Uh oh!
There was an error while loading. Please reload this page.
| } | ||
| public QueryLogger createQueryLogger(CompilableStatement stmt, String sql) throws SQLException { | ||
| if (connection.getLogLevel() == LogLevel.OFF) { |
There was a problem hiding this comment.
This looks suspect.
Shouldn't we check the audit log status too ?
| return compileMutation(stmt, sql); | ||
| } | ||
| public boolean checkIgnoreQueryAudit(CompilableStatement stmt, String sql) { |
There was a problem hiding this comment.
We could move the check for ExecutableSelectStatement here.
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
Change-Id: I0f0a39293500201c7a27a8fd8686799fb1668221
stoty
commented
Apr 27, 2021
Next time please push a separate commit instead of amending so that I can see what you changed. |
| boolean isSystemTable = false; | ||
| if(stmt instanceof ExecutableSelectStatement) { | ||
| public boolean checkIgnoreQueryAudit(CompilableStatement stmt) { |
There was a problem hiding this comment.
This is now applies to al logs, so we shouldn't call it checkIgnoreQueryAudit
| handlerCount = DEFAULT_AUDIT_LOGGER_PROCESS_COUNT; | ||
| } | ||
| QueryLogDetailsWorkHandler[] workHandlers = new QueryLogDetailsWorkHandler[handlerCount]; |
There was a problem hiding this comment.
We should remove the old handler, as it is dead code now.
| 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(); | ||
There was a problem hiding this comment.
nit: no need for the extra empty line
stoty
commented
Apr 27, 2021
Please also do a PR for 4.x when you are done, so that we get a test run on that branch, too. |
stoty
commented
Apr 27, 2021
💔 -1 overall
This message was automatically generated. |
Change-Id: Ieb0fed3f245a15297a34752b6a2b95f548eba396
stoty
commented
Apr 28, 2021
💔 -1 overall
This message was automatically generated. |
joshelser
left a comment
There was a problem hiding this comment.
I'd like to understand the intent of how a user would use this audit logging a bit better before these changes land.
Specifically, it looks like, right now, the log level has to be >= than the audit log level to function. However, I think that's not the intent of your changes. By the changes in this PR, I think you're intending for either the normal log or the audit log to result in data flowing to the system.log table.
In other words, it would be helpful to describe what someones sets in configuration who wants to get the audit logs, and then what these look like when they make it to the system.log table.
Thanks!
Uh oh!
There was an error while loading. Please reload this page.
| syncBase(readMetrics, overAllMetrics, logLevel); | ||
| } | ||
| public void syncAudit(Map<String, Map<MetricType, Long>> readMetrics, Map<MetricType, Long> overAllMetrics) { |
There was a problem hiding this comment.
Since your calls to this method are often passing (null, null), how about overloading this method to create
public void syncAudit() {
syncAudit(null, null, LogLevel.TRACE);
}
And then adopt that new call above. Would also be good to have javadoc (especially to denote the difference between sync and syncAudit)
| import com.lmax.disruptor.Sequence; | ||
| import com.lmax.disruptor.SequenceReportingEventHandler; | ||
| public class QueryLogDetailsWorkHandler implements WorkHandler<RingBufferEvent>, LifecycleAware { |
There was a problem hiding this comment.
Trying to understand the change of type hierarchy. Seems like we didn't actually need the Sequence part of disruptor?
There was a problem hiding this comment.
sequenceCallback was never used in the old implementation.
| this.queryId = UUID.randomUUID().toString(); | ||
| this.queryDisruptor = connection.getQueryServices().getQueryDisruptor(); | ||
| logLevel = connection.getLogLevel(); | ||
| auditLogLevel = connection.getAuditLogLevel(); |
There was a problem hiding this comment.
We're only using logLevel to determine when we should instantiate a real QueryLogger instance in getInstance(PhoenixConnection, boolean).
Is the expectation that a user could have audit logging without "normal" logging enabled? Right now, it looks like you have to have at least some "normal" logging enabled to get the audit logging.
I think we would want these to be exclusive (if either normal or audit logging is enabled, we instantiate a real QueryLogger).
There was a problem hiding this comment.
(can't comment on this line in the code, so putting it here)
We also only get a real QueryLogger when getLogSamplingRate() matches the condition inside getInstance(...). Is it OK to have just one sampling rate for both normal and audit logging?
There was a problem hiding this comment.
Great catch Josh!
We would like the QueryLogger work separately from the newly created AuditQueryLogger.
We should log DML and DDL operations when QueryServices.AUDIT_LOG_LEVEL is greater than INFO even if normal logging is disabled. (the default is OFF)
We can have both enabled and if we want to have logging for select queries and for DML + DDL queries, we should.
About the LogSamplingRate
In the latest change I separated AuditQueryLogger and LogSamplingRate has no effect on it, I think If AUDIT_LOG_LEVEL is enabled we should log every query.
There was a problem hiding this comment.
We can have both enabled and if we want to have logging for select queries and for DML + DDL queries, we should.
Great! That sounds like the correct approach.
In the latest change I separated AuditQueryLogger and LogSamplingRate has no effect on it, I think If AUDIT_LOG_LEVEL is enabled we should log every query.
Ok, I think that is fine. Let's make sure we circle back around an update Phoenix documentation for this new feature.
Change-Id: I3a7591c3224ebd54358f322981cde6b1d220002e
| auditLogLevel = LogLevel.OFF; | ||
| } | ||
| public static final AuditQueryLogger NO_OP_INSTANCE = new AuditQueryLogger() { |
There was a problem hiding this comment.
Looks like this mostly duplicates the NO_OP_INSTANCE in QueryLogger. Could clean this up (in follow-up) to not have the same "shell" of a class.
joshelser
left a comment
There was a problem hiding this comment.
Looks great. Awesome test case addition 👍🏼
Why the notion of a separate type of logger as opposed to increasing the scope of the queryLogger? More specifically can we make the logging class pluggable and have this as one of the implementations? We can also have a chain-able logger where more than one could be used if necessary. |
joshelser
commented
Apr 29, 2021
The earlier commits on this review actually had them both in one class. It was a little complex to manage not getting a no-op instance when either query logging or audit logging. |
The motivation for the audit logger is to log all data modifications for compliance purposes. The goal of the original logging implementation is mostly to provide data for operational purposes and performance optimization. For example, in query logging, we only log the parameters at trace levels, while in the audit log we always want to log them, as it's useless without this. We have serveral things to log (query, paramters, query plan, statistics, etc) However, this would be quite a large and awkward matrix to configure. The current solution is a relatively simple point solution to add the audit logging capability. It does not preclude the possibility of adding a more full-featured and flexible logging implementation later. |
dbwong
commented
Apr 29, 2021
This is already pushed but I'm a bit worried about how we migrate users on this to the more full-featured and flexible logging implementation without the approaches I mentioned above. We may have to support this into the future even if it isn't really as flexible as we would like. |
stoty
commented
Apr 29, 2021
💔 -1 overall
This message was automatically generated. |
joshelser
commented
Apr 29, 2021
I'm not seeing how this is making things worse -- as it stands, users who were using the query logger can continue to use it as they have been. Those who want to adopt the DDL audit logging can turn that on as they please. As Istvan points out, there's a big range out what users want when it comes to auditing. I don't see what is in place right now as being burdensome (you have to know it's there and turn it on by default, now). That's not to say we have to leave it this way (I think automatically logging DDLs would be excellent!), but let's focus on what we want this usability to be. Wdyt, Daniel? |
I'm not opposed to the short term implementation, i'm just trying to make the end user opt in more generic so we won't have a migration to do in the future, or alternatively have multiple ways to configure query logging. Do I use audit logging/query logging or whatever improvements we build in the future? Which was why I was trying to push for a generalized solution where we specify a logging class, for example phoenix.log.queryLogger=org.apache.phoenix.log.auditLogger. Otherwise we may end up having a giant grid of options like you mentioned. I'm not strongly opposed but note that future improvements may want to completely removing "auditLogger" options, but we will feel obligated to keep them for compatibility. |
stoty
commented
Apr 30, 2021
Being able to specify a single logging implementation wouldn't get us far. To support even the current use case, we'd need to be able to specify the logging class and log level for at least for the queries and the DML/DDL statements separately. The implementation detail of having a separate logger class is not exposed in the configuration. Once we figure out how to have more generic logging configuration, the current behaviour can be folded into that. I think that in more generic configuration we should have single logger and feed all logging events to that. That intelligent logger would then (pre) compute the aforementioned big matrix of what should go into the log based on the query type and what we specified in the new-style configuration, and add/ignore the events based on that. I agree that we WOULD have to add some backwards compatibility code to map the current settings to the future more flexible method, which is not ideal, but we'll have to do the same for the existing query logger configuration setting anyway. I gave some thought about how to add redaction to the logging, but it seeems pretty daunting. You could probably flag fields and identify them at statement compilation time, but then you'd have to re-generate the logged query text from the redacted query plan. (And I'm not sure how UDFs would interfere with this) |
joshelser
commented
Apr 30, 2021
Can I suggest this path forward? @richardantal and @stoty, can you please make sure the current functionality is documented on the webiste? Then, let's continue conversation with @dbwong (and others) on the mailing list to figure out, given what we have today, are there any scenarios which are impossible or hard which we would want to improve going forward. |
Change-Id: I0f0a39293500201c7a27a8fd8686799fb1668221