Enable toggling request logging on/off for different query types #7562

capistrant · 2019-04-26T21:49:14Z

Relates to #7115 and #5320

In reference to @gianm comment in #5320: I held off on making this a more involved enhancement that would allow ignoring only internal SegmentMetadata queries as opposed to all SegmentMetadata queries because I wasn't sure of the value add from doing that versus a blanket ignore of this type. I am certainly open to revisiting that and making this more than an on/off switch. (something like druid.request.logging.logSegmentMetadataQueries with the options all, none, internal_only, external_only that then leverages the identity in the query -- defaulting to logging all SegmentMetadata queries in clusters not using security and the config is not set to none)

stale · 2019-06-25T21:54:15Z

This pull request has been marked as stale due to 60 days of inactivity. It will be closed in 1 week if no further activity occurs. If you think that's incorrect or this pull request should instead be reviewed, please simply write any comment. Even if closed, you can still revive the PR at any time or discuss it on the dev@druid.apache.org list. Thank you for your contributions.

stale · 2019-07-02T22:27:19Z

This pull request/issue has been closed due to lack of activity. If you think that is incorrect, or the pull request requires review, you can revive the PR at any time.

capistrant · 2019-07-10T14:31:20Z

@gianm @Caroline1000 Any interest in reviving this PR to address the related issue regarding the logging here?

Caroline1000 · 2019-07-10T19:01:04Z

+1 for reviving. Having the all, none, internal_only, external_only options might be useful but not sure it's necessary.

stale · 2019-07-10T21:38:49Z

This pull request/issue is no longer marked as stale.

gianm · 2019-07-10T21:38:54Z

Reopened!!

gianm · 2019-07-11T19:56:39Z

docs/content/configuration/index.md

@@ -316,6 +316,7 @@ All processes that can serve queries can also log the query requests they see. B
 |Property|Description|Default|
 |--------|-----------|-------|
 |`druid.request.logging.type`|Choices: noop, file, emitter, slf4j, filtered, composing, switching. How to log every query request.|[required to configure request logging]|
+| `druid.request.logging.logSegmentMetadataQueries`| Boolean indicating if SegmentMetadata Queries should be logged by the Request Logger.| true|


I think the way this property behaves is good, but it would be better inside FilteredRequestLogger. That way, it's composable, rather than needing to be implemented inside each and every RequestLogger.

…he filtered request logger

leventov

I think the overall approach is still unnecessarily specific. It would be more generic if a config accepts a list of query types which shouldn't be logged.

leventov · 2019-07-12T17:54:31Z

server/src/main/java/org/apache/druid/server/log/FilteredRequestLoggerProvider.java


-    public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs)
+    public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs,


According to Druid style, should chop down the list of params:

Suggested change

public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs,

public FilteredRequestLogger(

RequestLogger logger,

long queryTimeThresholdMs,

long sqlQueryTimeThresholdMs,

boolean logSegmentMetadataQueries

)

{

You might want to look into using spotless as a pre-push hook so that you don't have to catch styling issues in code review. It will automatically re-format the code according to a provided style guide
https://github.com/diffplug/spotless/tree/master/plugin-maven#applying-to-java-source

(long time lurker) Sorry if this is a redundant suggestion and you already have another tool that does similar stuff

capistrant · 2019-07-12T18:23:28Z

@leventov That sounds like a good idea to me. How would you propose handling erroneous entries by users? Hard failure, Ignore with a warning log, other?

leventov · 2019-07-15T15:33:45Z

@capistrant I think hard failure would be in line with the existing code in Druid, e. g. in EmitterModule:

https://github.com/apache/incubator-druid/blob/ffa25b78321a56b210a8ad5b6c9ca61b3b737153/server/src/main/java/org/apache/druid/server/emitter/EmitterModule.java#L143-L151

leventov · 2019-07-15T17:04:16Z

However, according to the policy proposed by @drcrallen here: #8083 (comment) (and which I think is reasonable), there should be only a warning, not a hard failure.

drcrallen · 2019-07-16T00:13:59Z

In line with #8083 (comment) I agree it should be a warning. If my understanding is correct, miss-configuration in such a scenario would bring the behavior closer to the "default" behavior (i.e. worst case is it is reconciled to behave no different than if it weren't configured).

capistrant · 2019-07-16T18:29:10Z

Thanks all for the tips and info! I'll be cleaning this up this week following all the feedback

…logger

leventov · 2019-08-01T17:46:49Z

docs/content/configuration/index.md

@@ -379,6 +379,7 @@ For native query, only request logs where query/time is above the threshold are
 |--------|-----------|-------|
 |`druid.request.logging.queryTimeThresholdMs`|Threshold value for query/time in milliseconds.|0 i.e no filtering|
 |`druid.request.logging.sqlQueryTimeThresholdMs`|Threshold value for sqlQuery/time in milliseconds.|0 i.e no filtering|
+|`druid.request.logging.queryTypeBlacklist` | List of Druid query types to exclude from request logs. Query types are defined as string objects in the Query interface found in Query.java. Mispelled query types will be ignored. Example to ignore scan and timeBoundary queries: ["scan", "timeBoundary"]| []|


queryTypeBlacklist sounds a little intimidating. I would say "mutedQueryTypes".

I suggest the description:

```suggestion |`druid.request.logging.mutedQueryTypes` | Query requests of these types are not logged. Query types are defined as string objects corresponding to the "queryType" value for the specified query in the Druid's [native JSON query API](http://druid.apache.org/docs/latest/querying/querying.html). Misspelled query types will be ignored. Example to ignore scan and timeBoundary queries: ["scan", "timeBoundary"]| []|

leventov · 2019-08-01T17:51:36Z

server/src/main/java/org/apache/druid/server/log/FileRequestLoggerProvider.java

@@ -58,7 +58,8 @@
  @Override
  public RequestLogger get()
  {
-    FileRequestLogger logger = new FileRequestLogger(jsonMapper, factory.create(1, "RequestLogger-%s"), dir, filePattern);
+    FileRequestLogger logger = new FileRequestLogger(jsonMapper, factory.create(1, "RequestLogger-%s"), dir,
+        filePattern);


Please chop down all arguments (each on its own line) if they don't fit a line.

got it. I've got to stop forgetting about that one, thanks for the comment

leventov · 2019-08-01T17:52:00Z

server/src/main/java/org/apache/druid/server/log/FilteredRequestLoggerProvider.java


-    public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs)
+    public FilteredRequestLogger(RequestLogger logger,


Please chop down params: #7562 (comment)

leventov · 2019-08-01T17:53:39Z

server/src/test/java/org/apache/druid/server/log/FilteredRequestLoggerTest.java

@@ -106,6 +113,10 @@ public void testNotFilterAboveThreshold() throws IOException
    EasyMock.expect(nativeRequestLogLine.getQueryStats())
            .andReturn(new QueryStats(ImmutableMap.of("query/time", 1000)))
            .once();
+    EasyMock.expect(nativeRequestLogLine.getQuery())
+            .andReturn(new SegmentMetadataQuery(new LegacyDataSource("foo"),


Please extract new SegmentMetadataQuery(...) as a variable.

Wasn't sure if I should do one final class variable or two local variables (one per method). Went with the former, but would be easy to change to something else if my choice happens to be considered a bad pattern in Java

leventov · 2019-08-01T17:53:44Z

server/src/test/java/org/apache/druid/server/log/FilteredRequestLoggerTest.java

@@ -114,6 +125,10 @@ public void testNotFilterAboveThreshold() throws IOException
    EasyMock.expect(sqlRequestLogLine.getQueryStats())
            .andReturn(new QueryStats(ImmutableMap.of("sqlQuery/time", 2000)))
            .once();
+    EasyMock.expect(sqlRequestLogLine.getQuery())
+            .andReturn(new SegmentMetadataQuery(new LegacyDataSource("foo"),


leventov · 2019-08-01T17:53:54Z

server/src/test/java/org/apache/druid/server/log/FilteredRequestLoggerTest.java

+            .andReturn(new QueryStats(ImmutableMap.of("query/time", 10000)))
+            .once();
+    EasyMock.expect(nativeRequestLogLine.getQuery())
+            .andReturn(new SegmentMetadataQuery(new LegacyDataSource("foo"),


leventov · 2019-08-01T17:53:59Z

server/src/test/java/org/apache/druid/server/log/FilteredRequestLoggerTest.java

+            .andReturn(new QueryStats(ImmutableMap.of("sqlQuery/time", 10000)))
+            .once();
+    EasyMock.expect(sqlRequestLogLine.getQuery())
+            .andReturn(new SegmentMetadataQuery(new LegacyDataSource("foo"),


capistrant · 2019-08-02T14:11:36Z

I'm not sure how to interpret the TeamCity Failure. I'm looking in the errors in the report but don't see any of the files I changed in the files listed as error.

gianm · 2019-08-02T15:49:04Z

I'm not sure either. I triggered the job to run again, in case it was something weird with that run.

gianm · 2019-08-02T15:49:32Z

If you haven't merged master into your branch recently, sometimes that helps. You could try that if TC bombs out again.

capistrant · 2019-08-02T19:11:15Z

Thanks @gianm, restarting it seemed to do the trick 👍

leventov · 2019-08-05T16:15:06Z

server/src/main/java/org/apache/druid/server/log/FileRequestLoggerProvider.java

-    FileRequestLogger logger = new FileRequestLogger(jsonMapper, factory.create(1, "RequestLogger-%s"), dir,
-        filePattern);
+    FileRequestLogger logger = new FileRequestLogger(
+            jsonMapper,


In Druid, the wrapping indentation is 4, not 8 spaces. Please also fix other places in this PR.

capistrant · 2019-08-05T18:40:45Z

server/src/test/java/org/apache/druid/server/log/FilteredRequestLoggerTest.java

@@ -106,6 +123,9 @@ public void testNotFilterAboveThreshold() throws IOException
    EasyMock.expect(nativeRequestLogLine.getQueryStats())
            .andReturn(new QueryStats(ImmutableMap.of("query/time", 1000)))
            .once();
+    EasyMock.expect(nativeRequestLogLine.getQuery())


@leventov Does that wrapping indentation of 4 standard include lines such as these 3? I see that the lines above and below are had been using 8.

No. Here, the alignment is on the dot. It's a coincidence that "EasyMock" is 8 characters long.

leventov · 2019-08-06T12:47:26Z

@capistrant thanks for following through!

capistrant · 2019-08-06T16:37:20Z

@leventov Thanks for the review and guidance for this PR! I'll work to get my editor better set up to comply with Druid style rules and have some automated checks client side so there is less back and forth regarding those tedious errors in the future 👍

Caroline1000 · 2019-08-06T18:25:43Z

thank you @capistrant ! 🎉

Enable ability to toggle SegmentMetadata request logging on/off

cd33171

stale bot added the stale label Jun 25, 2019

stale bot closed this Jul 2, 2019

gianm reopened this Jul 10, 2019

stale bot removed the stale label Jul 10, 2019

gianm reviewed Jul 11, 2019

View reviewed changes

capistrant added 2 commits July 12, 2019 11:56

Move SegmentMetadata query log filter to FilteredRequestLogger

a05cf3b

Update documentation to reflect the segment metadata flag moving to t…

6581966

…he filtered request logger

leventov reviewed Jul 12, 2019

View reviewed changes

leventov mentioned this pull request Jul 15, 2019

Principle for treating configuration errors #8083

Open

Modify patch to allow blacklist of query types to not log to request …

c9ace99

…logger

leventov added the Area - Operations label Aug 1, 2019

leventov changed the title ~~Enable ability to toggle SegmentMetadata request logging on/off~~ Enable ability to toggle request logging on/off for different query types Aug 1, 2019

leventov changed the title ~~Enable ability to toggle request logging on/off for different query types~~ Enable toggling request logging on/off for different query types Aug 1, 2019

leventov requested changes Aug 1, 2019

View reviewed changes

Address styling and naming requests following latest code review

c88ebc6

leventov requested changes Aug 5, 2019

View reviewed changes

capistrant commented Aug 5, 2019

View reviewed changes

Fix indentation on multiple locations per Druid style rules

96d7905

leventov approved these changes Aug 5, 2019

View reviewed changes

leventov added the Release Notes label Aug 6, 2019

leventov added this to the 0.16.0 milestone Aug 6, 2019

leventov merged commit e252abe into apache:master Aug 6, 2019

leventov mentioned this pull request Aug 6, 2019

Modify FilteredRequestLogger to suppress segmentMetadata queries #7115

Closed

clintropolis mentioned this pull request Aug 21, 2019

0.16.0-incubating release notes #8369

Closed


		public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs)
		public FilteredRequestLogger(RequestLogger logger, long queryTimeThresholdMs, long sqlQueryTimeThresholdMs,

Enable toggling request logging on/off for different query types #7562

Enable toggling request logging on/off for different query types #7562

Conversation

capistrant commented Apr 26, 2019

stale bot commented Jun 25, 2019

stale bot commented Jul 2, 2019

capistrant commented Jul 10, 2019

Caroline1000 commented Jul 10, 2019

stale bot commented Jul 10, 2019

gianm commented Jul 10, 2019

Choose a reason for hiding this comment

leventov left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

capistrant commented Jul 12, 2019

leventov commented Jul 15, 2019

leventov commented Jul 15, 2019

drcrallen commented Jul 16, 2019

capistrant commented Jul 16, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

capistrant commented Aug 2, 2019

gianm commented Aug 2, 2019

gianm commented Aug 2, 2019

capistrant commented Aug 2, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

leventov commented Aug 6, 2019

capistrant commented Aug 6, 2019

Caroline1000 commented Aug 6, 2019