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 2022/09/25 13:41:32 UTC

[GitHub] [kafka] ashmeet13 opened a new pull request, #12684: KAFKA-14254; Format timestamps as dates in logs

ashmeet13 opened a new pull request, #12684:
URL: https://github.com/apache/kafka/pull/12684

   Improves logs by replacing timestamps to date instances to improve readability.
   
   `StreamsPartitionAssignor.java`
   
   ```
   Before - [2022-09-24 18:26:24,342] INFO stream-thread [] Requesting followup rebalance be scheduled by consumer10 for 1664024784341 ms to probe for caught-up replica tasks. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:960)
   
   After - [2022-09-24 18:28:24,248] INFO stream-thread [] Requesting followup rebalance be scheduled by consumer10 for 2022-09-24T13:08:24.247Z to probe for caught-up replica tasks. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:960)
   ```
   
   `StreamThread.java`
   
   ```
   Before - [2022-09-25 15:16:41,624] INFO stream-thread [stream-thread-test-87bf53a8-54f2-485f-a4b6-acdbec0a8b3d-StreamThread-1] Triggering the followup rebalance scheduled for 1664099201495 ms. (org.apache.kafka.streams.processor.internals.StreamThread:613)
   
   After - [2022-09-25 18:49:21,813] INFO stream-thread [stream-thread-test-87bf53a8-54f2-485f-a4b6-acdbec0a8b3d-StreamThread-1] Triggering the followup rebalance scheduled for 2022-09-25T13:19:21.808Z. (org.apache.kafka.streams.processor.internals.StreamThread:614)
   ```
   
   
   ### 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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] divijvaidya commented on a diff in pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
divijvaidya commented on code in PR #12684:
URL: https://github.com/apache/kafka/pull/12684#discussion_r997381071


##########
streams/src/main/java/org/apache/kafka/streams/processor/internals/StreamsPartitionAssignor.java:
##########
@@ -1447,6 +1450,11 @@ private int updateMinSupportedVersion(final int supportedVersion, final int minS
         }
     }
 
+    private String formatInstantTime(final long instant) {

Review Comment:
   As you suggested, this function would be a better fit for a Util class because it's being used twice across two different classes.
   
   Perhaps rename it to `ToLogDateTimeFormat()` and add it to a new class `commons.utils.LoggingUtils`



-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1285933864

   Thanks @divijvaidya for the review. I have added the function as you suggested under `commons.utils`.
   
   Would you suggest defining a completely new class for `LoggingUtils` with just the `ToLogDateTimeFormat()` function?
   For now I have added this function within the existing`Utils` class.


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1281173832

   Hi @vvcephei, bumping this PR up in case it got missed. Could please have a look at this?


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1272513555

   Hi @divijvaidya, @vvcephei - I have made the suggested changes and defined a new function to convert timestamps to a readable format - 
   
   ```
   private String formatInstantTime(final long instant) {
           final DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS");
           return Instant.ofEpochMilli(instant).atZone(ZoneId.systemDefault()).format(dateTimeFormatter);
       }
   ```
   
   Currently defined within the classes it is needed for though I believe this function is better defined within a `utils` package. Not sure where that would be.
   
   Please have a look at the implementation and let me know if any improvements are required.


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] divijvaidya commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
divijvaidya commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1259199080

   1. (Calling this out for completeness sake) `Instant.ofEpochMilli` is slower than existing solution but it is worth making this change for the sake of readability of logs. It will improve operator's life while debugging logs.
   
   2. Another aspect that impacts readability is that the consistency of time representation in the logs. For example, the pattern used to format the timestamp of the log at the beginning of the line is `2022-09-24 18:28:24,248` (DEFAULT pattern for SimpleDateFormatter) but the format of time for nextProbingRebalance after this change is ISO_8601 i.e. `2022-09-24T13:08:24.247Z`. The `nextProbingRebalance` will always be in UTC but the time at the beginning of the log line will be as per system's default timezone. This will cause confusion for the operator. Hence, I would suggest to follow the same time zone (and preferably the same date format) as the log4j formatter to represent human readable time in middle of the logs.


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1264352757

   Hey @divijvaidya,
   Thank you for the inputs. With respect to the second point - do you think we should replace the current implementation from `Instant.ofEpochMilli` to something like - 
   ```
   final String nextRebalanceTime = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss,SSS").format(new Date(nextRebalanceTimeMs));
   ```
   
   and use `nextRebalanceTime` in logs?
   
   ---
   A preview of how the logs are now - 
   
   ```
   [2022-10-01 18:07:52,605] INFO stream-thread [] Requesting followup rebalance be scheduled by consumer10 for 2022-10-01 18:17:52,601 to probe for caught-up replica tasks. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:964)
   ```


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1257197736

   Hi @vvcephei, could you please review this PR.
   Thank you.


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] cadonna commented on a diff in pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
cadonna commented on code in PR #12684:
URL: https://github.com/apache/kafka/pull/12684#discussion_r1009410493


##########
clients/src/main/java/org/apache/kafka/common/utils/Utils.java:
##########
@@ -1450,4 +1453,15 @@ public static String[] enumOptions(Class<? extends Enum<?>> enumClass) {
                 .toArray(String[]::new);
     }
 
+    /**
+     * Convert time instant to readable string for logging
+     * @param timestamp the timestamp of the instant to be converted.
+     *
+     * @return string value of a given timestamp in the format "yyyy-MM-dd HH:mm:ss,SSS"
+     */
+    public static String toLogDateTimeFormat(long timestamp) {
+        final DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS");

Review Comment:
   Would it be possible to add the timezone to the pattern? For example, assuming the system default is UTC+02:00, the time could contain +02:00. 



-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] cadonna merged pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
cadonna merged PR #12684:
URL: https://github.com/apache/kafka/pull/12684


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on a diff in pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on code in PR #12684:
URL: https://github.com/apache/kafka/pull/12684#discussion_r1013311309


##########
clients/src/main/java/org/apache/kafka/common/utils/Utils.java:
##########
@@ -1450,4 +1453,15 @@ public static String[] enumOptions(Class<? extends Enum<?>> enumClass) {
                 .toArray(String[]::new);
     }
 
+    /**
+     * Convert time instant to readable string for logging
+     * @param timestamp the timestamp of the instant to be converted.
+     *
+     * @return string value of a given timestamp in the format "yyyy-MM-dd HH:mm:ss,SSS"
+     */
+    public static String toLogDateTimeFormat(long timestamp) {
+        final DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS");

Review Comment:
   Hi @cadonna, Thank you for the review!
   I have added the change for this. A few sample logs with the updated datetime format -
   
   ```
   [2022-11-04 00:36:28,517] INFO stream-thread [stream-thread-test-87bf53a8-54f2-485f-a4b6-acdbec0a8b3d-StreamThread-1] Triggering the followup rebalance scheduled for 2022-11-04 00:36:28,511 +05:30. (org.apache.kafka.streams.processor.internals.StreamThread:614)
   ```
   ```
   [2022-11-04 00:46:52,220] INFO stream-thread [] Requesting followup rebalance be scheduled by consumer10 for 2022-11-04 00:56:52,212 +05:30 to probe for caught-up replica tasks. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:960)
   ```



-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1296554205

   Hi @cadonna, could you please review this PR?
   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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] cadonna commented on pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
cadonna commented on PR #12684:
URL: https://github.com/apache/kafka/pull/12684#issuecomment-1305550037

   Build failures are unrelated:
   ```
   Build / JDK 11 and Scala 2.13 / org.apache.kafka.clients.consumer.CooperativeStickyAssignorTest.testLargeAssignmentAndGroupWithNonEqualSubscription()
   Build / JDK 11 and Scala 2.13 / org.apache.kafka.clients.consumer.StickyAssignorTest.testLargeAssignmentAndGroupWithNonEqualSubscription()
   ```


-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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


[GitHub] [kafka] ashmeet13 commented on a diff in pull request #12684: KAFKA-14254; Format timestamps as dates in logs

Posted by GitBox <gi...@apache.org>.
ashmeet13 commented on code in PR #12684:
URL: https://github.com/apache/kafka/pull/12684#discussion_r1013311309


##########
clients/src/main/java/org/apache/kafka/common/utils/Utils.java:
##########
@@ -1450,4 +1453,15 @@ public static String[] enumOptions(Class<? extends Enum<?>> enumClass) {
                 .toArray(String[]::new);
     }
 
+    /**
+     * Convert time instant to readable string for logging
+     * @param timestamp the timestamp of the instant to be converted.
+     *
+     * @return string value of a given timestamp in the format "yyyy-MM-dd HH:mm:ss,SSS"
+     */
+    public static String toLogDateTimeFormat(long timestamp) {
+        final DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss,SSS");

Review Comment:
   Hi @cadonna, I have added the change for this. A few sample logs with the updated datetime format -
   
   ```
   [2022-11-04 00:36:28,517] INFO stream-thread [stream-thread-test-87bf53a8-54f2-485f-a4b6-acdbec0a8b3d-StreamThread-1] Triggering the followup rebalance scheduled for 2022-11-04 00:36:28,511 +05:30. (org.apache.kafka.streams.processor.internals.StreamThread:614)
   ```
   ```
   [2022-11-04 00:46:52,220] INFO stream-thread [] Requesting followup rebalance be scheduled by consumer10 for 2022-11-04 00:56:52,212 +05:30 to probe for caught-up replica tasks. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:960)
   ```



-- 
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.

To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org

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