refactor: remove logging for every pull query MINOR #3736

vpapavas · 2019-11-04T19:24:32Z

Description

Fixes #3672
Remove logging at info level for every pull query. It floods the server.
Logging is done for errors already so that can be used for debugging.

Testing done

Describe the testing strategy. Unit and integration tests are expected for any behavior changes.

Reviewer checklist

Ensure docs are updated if necessary. (eg. if a user visible feature is being added or changed).
Ensure relevant issues are linked (description should include text like "Fixes #")

ghost · 2019-11-04T19:24:34Z

@confluentinc It looks like @vpapavas just signed our Contributor License Agreement. 👍

Always at your service,

clabot

agavra

won't this affect all queries, not just pull query logging? I feel like this log is useful at some level to know what we've been receiving.

Even for pull queries, I think we should be logging this (perhaps on a different logger). For previous projects*, we'd log all requests including a traceID, the time, the duration, the issuer etc... to help not only debug bad queries, but identify classes of queries that were problematic. I think we should consider doing something like that for pull queries (and it doubles as a primitive audit log). cc @vinothchandar

* the project was a search system handling hundreds of QPS, and the logs would roll on an hourly basis and be cleaned up after 7 days

vinothchandar

Guess it's subjective. I prefer not to log every request unless 'interesting' things (errors, asserts failing) happen on them. +1 on having a separate log though, it will flood the ksql-server log completely otherwise.

That said, may be we can file a separate issue for that? For now, we probably just want to avoid logging per request.

vinothchandar · 2019-11-04T21:24:52Z

ksql-rest-app/src/main/java/io/confluent/ksql/rest/server/resources/KsqlResource.java

@@ -195,7 +195,6 @@ public Response handleKsqlStatements(
      @Context final ServiceContext serviceContext,
      final KsqlRequest request
  ) {
-    LOG.info("Received: " + request);


could we introduce a log statement somewhere (say where we check for isStatic) that logs the sql statement? That way for non pull queries you still have similar log statement (which i guess would be useful)

agavra · 2019-11-04T21:29:04Z

That said, may be we can file a separate issue for that? For now, we probably just want to avoid logging per request.

+1 I'll file a ticket for that

EDIT: #3741 - I assigned it to @vinothchandar, but feel free to hot potato it.

…ull query

agavra · 2019-11-05T01:07:29Z

ksql-rest-app/src/main/java/io/confluent/ksql/rest/server/validation/RequestValidator.java

@@ -108,6 +109,11 @@ public int validate(
      final ConfiguredStatement<?> configured = ConfiguredStatement.of(
          prepared, scopedPropertyOverrides, ksqlConfig);

+      final Class<? extends Statement> statementClass = prepared.getStatement().getClass();


will #3742 solve the need for this PR? after looking at this patch, it seems very out of place to have this in the validator!

we still have to discuss that and I expect we will hash it out over the next week or so. So may not have time to land before the release cut. In this scenario, its better to have some fix landed first and then iterate? We should make a note and undo these bandaids +1 on that.

Yes, #3742 solve the need for this PR. I added the check in the validator because PR #3711 also requires this check and I didn't want to do it twice.

rodesai · 2019-11-05T02:44:19Z

Why are we removing the log msg altogether? We could just as well of at a more verbose level. If the cost of generating the message is a concern, we can log using the format string interfaces to avoid toString on every call.

agavra

Approving to unblock the release, please get one more +1 since this is semi-controversial despite being such a small change 😂 - make sure to rebase this on 5.4.x, and also please add a ticket to move this back after #3742

@rodesai - I think the concern is not performance but spamming the log. I wanted to have the log at INFO level even for normal operation for persistent queries, it's pretty useful to debug things, but it makes sense to have it at DEBUG for pull queries.

vinothchandar · 2019-11-05T17:15:35Z

The root issue is introducing this statement in the hot path for pull queries. We can also simply remove this for now and think about it in #3741 .. @big-andy-coates can you please chime in here? Are you okay with not having this log statement for now?

big-andy-coates

Switching the pull queries over to the /query end point will fix this issue. We shouldn't commit this change.

vinothchandar · 2019-11-06T18:54:27Z

@big-andy-coates its not clear to me yet, if the switch to /query is targeted for next week? Can we just disable the log statement or move it to DEBUG for now and remove special casing like I mentioned before? We make move it back to INFO once pull queries are off this end point..

vinothchandar · 2019-11-07T14:39:20Z

@big-andy-coates any updates? I am leaning towards simplifying this PR to just remove/change level for the log statement and merge, while we figure out the timelines for moving to /query.

apurvam · 2019-11-08T06:40:30Z

I think at this point, we should not be moving functionality to the /query endpoint right now for the following reasons:

I think we will have to re think the API any way and moving pull queries to the /query endpoint is likely not the final state.
having chunked and non-chunked responses in the same endpoint directly jeopardizes the work on grafana integration which is underway to enable an internal use case on KSQL. (see InfluxDB: take advantage of influx chunked reponses grafana/grafana#863)

@vchandar @vicky please feel free to merge your PR and get unblocked. Let’s not pursue any parallel tracks of work to move pull query functionality into the /query endpoint right now. We can think of a redesign of the API to account for the new query types as a separate track of work afterwards. We know we are going to make a bunch of breaking changes, and this can be part of the batch.

vpapavas · 2019-11-14T22:05:27Z

Closing this PR since pull queries moved to the /query endpoint that does not do logging.

remove logging for every pull query

c979417

vpapavas requested a review from a team as a code owner November 4, 2019 19:24

agavra reviewed Nov 4, 2019

View reviewed changes

agavra requested a review from a team November 4, 2019 19:40

vinothchandar reviewed Nov 4, 2019

View reviewed changes

agavra mentioned this pull request Nov 4, 2019

Add a Structured Query Logger #3741

Open

Moved logging to validator that performs check whether statement is p…

33ae778

…ull query

agavra reviewed Nov 5, 2019

View reviewed changes

agavra approved these changes Nov 5, 2019

View reviewed changes

agavra requested review from rodesai and a team November 5, 2019 16:48

big-andy-coates suggested changes Nov 6, 2019

View reviewed changes

vpapavas changed the title ~~feat: remove logging for every pull query MINOR~~ refactor: remove logging for every pull query MINOR Nov 6, 2019

vpapavas closed this Nov 14, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

refactor: remove logging for every pull query MINOR #3736

refactor: remove logging for every pull query MINOR #3736

vpapavas commented Nov 4, 2019 •

edited

Loading

ghost commented Nov 4, 2019

agavra left a comment •

edited

Loading

vinothchandar left a comment

vinothchandar Nov 4, 2019

agavra commented Nov 4, 2019 •

edited

Loading

agavra Nov 5, 2019

vinothchandar Nov 5, 2019

vpapavas Nov 5, 2019

rodesai commented Nov 5, 2019 •

edited

Loading

agavra left a comment •

edited

Loading

vinothchandar commented Nov 5, 2019

big-andy-coates left a comment

vinothchandar commented Nov 6, 2019

vinothchandar commented Nov 7, 2019

apurvam commented Nov 8, 2019

vpapavas commented Nov 14, 2019

refactor: remove logging for every pull query MINOR #3736

refactor: remove logging for every pull query MINOR #3736

Conversation

vpapavas commented Nov 4, 2019 • edited Loading

Description

Testing done

Reviewer checklist

ghost commented Nov 4, 2019

agavra left a comment • edited Loading

Choose a reason for hiding this comment

vinothchandar left a comment

Choose a reason for hiding this comment

vinothchandar Nov 4, 2019

Choose a reason for hiding this comment

agavra commented Nov 4, 2019 • edited Loading

agavra Nov 5, 2019

Choose a reason for hiding this comment

vinothchandar Nov 5, 2019

Choose a reason for hiding this comment

vpapavas Nov 5, 2019

Choose a reason for hiding this comment

rodesai commented Nov 5, 2019 • edited Loading

agavra left a comment • edited Loading

Choose a reason for hiding this comment

vinothchandar commented Nov 5, 2019

big-andy-coates left a comment

Choose a reason for hiding this comment

vinothchandar commented Nov 6, 2019

vinothchandar commented Nov 7, 2019

apurvam commented Nov 8, 2019

vpapavas commented Nov 14, 2019

vpapavas commented Nov 4, 2019 •

edited

Loading

agavra left a comment •

edited

Loading

agavra commented Nov 4, 2019 •

edited

Loading

rodesai commented Nov 5, 2019 •

edited

Loading

agavra left a comment •

edited

Loading