You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by GitBox <gi...@apache.org> on 2020/06/23 18:48:16 UTC

[GitHub] [kafka] cyrusv opened a new pull request #8918: Use debug level logging for noisy log messages in Connect

cyrusv opened a new pull request #8918:
URL: https://github.com/apache/kafka/pull/8918


   This very simply reduces the log level for these very frequently logged, very infrequently useful log messages to debug level.
   My experience operating these connectors is that these logs make reading info level logs quite cluttered. The MDC context certainly helps filter, but I think debug is more appropriate here -- if the log level were debug and someone wanted to promote it to info, that certainly would be an odd desire!
   
   ### Committer Checklist (excluded from commit message)
   - [ ] Verify design and implementation 
   - [ ] Verify test coverage and CI build status
   - [ ] Verify documentation (including upgrade notes)
   


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] wicknicks commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
wicknicks commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r451281466



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -571,7 +571,7 @@ public boolean commitOffsets() {
         finishSuccessfulFlush();
         long durationMillis = time.milliseconds() - started;
         recordCommitSuccess(durationMillis);
-        log.info("{} Finished commitOffsets successfully in {} ms",
+        log.debug("{} Finished commitOffsets successfully in {} ms",

Review comment:
       I think you missed this one. 




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] rhauch commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
rhauch commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r504920005



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -492,7 +492,7 @@ public boolean commitOffsets() {
             // to persistent storage
 
             // Next we need to wait for all outstanding messages to finish sending
-            log.info("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());
+            log.debug("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());

Review comment:
       Yeah, I think the log messages other than this one are fine as DEBUG.




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r504916758



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -492,7 +492,7 @@ public boolean commitOffsets() {
             // to persistent storage
 
             // Next we need to wait for all outstanding messages to finish sending
-            log.info("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());
+            log.debug("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());

Review comment:
       I do not feel strongly about this particular message -- it represents about 2% of the connect log volume in my deployment, so not too bad. Are you still onboard with the other log levels I've updated in the PR? In which case, I will revert this one?




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] rhauch merged pull request #8918: MINOR: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
rhauch merged pull request #8918:
URL: https://github.com/apache/kafka/pull/8918


   


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] ryannedolan commented on pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
ryannedolan commented on pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#issuecomment-654570254


   makes sense to me, thanks


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] rhauch commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
rhauch commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r481251133



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -475,7 +475,7 @@ private synchronized void recordSent(final ProducerRecord<byte[], byte[]> record
     public boolean commitOffsets() {
         long commitTimeoutMs = workerConfig.getLong(WorkerConfig.OFFSET_COMMIT_TIMEOUT_MS_CONFIG);
 
-        log.info("{} Committing offsets", this);
+        log.trace("{} Committing offsets", this);

Review comment:
       Why set this to `trace` rather than `debug` like the other changes? Isn't it useful to know that we've entered this method before we lock?

##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -571,7 +571,7 @@ public boolean commitOffsets() {
         finishSuccessfulFlush();
         long durationMillis = time.milliseconds() - started;
         recordCommitSuccess(durationMillis);
-        log.info("{} Finished commitOffsets successfully in {} ms",
+        log.trace("{} Finished commitOffsets successfully in {} ms",

Review comment:
       Same question here about `trace` vs `debug`, as denoted above. With debug logs, isn't it useful to know how long it took to commit all offsets?




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] wicknicks commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
wicknicks commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r451258641



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSinkTask.java
##########
@@ -343,7 +343,7 @@ private void doCommitSync(Map<TopicPartition, OffsetAndMetadata> offsets, int se
     }
 
     private void doCommitAsync(Map<TopicPartition, OffsetAndMetadata> offsets, final int seqno) {
-        log.info("{} Committing offsets asynchronously using sequence number {}: {}", this, seqno, offsets);
+        log.debug("{} Committing offsets asynchronously using sequence number {}: {}", this, seqno, offsets);

Review comment:
       these shouldn't be noisy. there is some [dedup logic](https://github.com/apache/kafka/blob/2.5.0/connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSinkTask.java#L430-L434) that should prevent the same message from being printed over and over again.

##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -475,7 +475,7 @@ private synchronized void recordSent(final ProducerRecord<byte[], byte[]> record
     public boolean commitOffsets() {
         long commitTimeoutMs = workerConfig.getLong(WorkerConfig.OFFSET_COMMIT_TIMEOUT_MS_CONFIG);
 
-        log.info("{} Committing offsets", this);
+        log.debug("{} Committing offsets", this);

Review comment:
       nit: since this is indicating entry into a method, I think it can be trace level.

##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -571,7 +571,7 @@ public boolean commitOffsets() {
         finishSuccessfulFlush();
         long durationMillis = time.milliseconds() - started;
         recordCommitSuccess(durationMillis);
-        log.info("{} Finished commitOffsets successfully in {} ms",
+        log.debug("{} Finished commitOffsets successfully in {} ms",

Review comment:
       nit: since this is mostly indicating exit from the method, I think it can be trace level too.




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#issuecomment-654549765


   @wicknicks, @C0urante, @ryannedolan:
   Any feedback on this one? It will make logs on many systems much less expensive in the normal case.


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r504963920



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -492,7 +492,7 @@ public boolean commitOffsets() {
             // to persistent storage
 
             // Next we need to wait for all outstanding messages to finish sending
-            log.info("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());
+            log.debug("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());

Review comment:
       Sounds good, updated




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#issuecomment-655285115


   @kkonstantine or @rhauch  -- This has some traction and nonbinding approval -- I think we're ready for committer review?


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r483196061



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -571,7 +571,7 @@ public boolean commitOffsets() {
         finishSuccessfulFlush();
         long durationMillis = time.milliseconds() - started;
         recordCommitSuccess(durationMillis);
-        log.info("{} Finished commitOffsets successfully in {} ms",
+        log.trace("{} Finished commitOffsets successfully in {} ms",

Review comment:
       @rhauch, The duration is an interesting point. I was considering that this is tracing exit of a function which already has debug in it. I think the duration is an aspect I hadn't considered, so I'll be happy to make these all uniformly debug level




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] rhauch commented on a change in pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
rhauch commented on a change in pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#discussion_r504899011



##########
File path: connect/runtime/src/main/java/org/apache/kafka/connect/runtime/WorkerSourceTask.java
##########
@@ -492,7 +492,7 @@ public boolean commitOffsets() {
             // to persistent storage
 
             // Next we need to wait for all outstanding messages to finish sending
-            log.info("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());
+            log.debug("{} flushing {} outstanding messages for offset commit", this, outstandingMessages.size());

Review comment:
       I'm not convinced that changing this to DEBUG is worth it. The number of source records output in this log message can be instrumental in some cases.
   
   For example, if the producer does not keep up with the source task (for whatever reason), this currently INFO-level message appears shortly before the following ERROR-level message:
   ```
   ... ERROR WorkerSourceTask{id=...} Failed to commit offsets (org.apache.kafka.connect.runtime.SourceTaskOffsetCommitter)
   ```
   The number of outstanding source records reported by this line is an important factor in determining how to tune the producer and `offset.flush.timeout.ms` value.
   
   




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#issuecomment-655277982


   @C0urante, @wicknicks -- I downgraded two of the SourceTask even further to Trace, so only the central log statement is debug level. 
   
   @wicknicks I see your point about dedup in SinkTask, but even with dedup it's still just not that useful of a log in my opinion to warrant Info level. Happy to discuss more if you disagree and think 


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [kafka] cyrusv commented on pull request #8918: Use debug level logging for noisy log messages in Connect

Posted by GitBox <gi...@apache.org>.
cyrusv commented on pull request #8918:
URL: https://github.com/apache/kafka/pull/8918#issuecomment-709483443


   @rhauch, thanks for the review, I've made the requested changes.


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org