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 2021/06/18 20:52:21 UTC

[GitHub] [kafka] xdgrulez opened a new pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

xdgrulez opened a new pull request #10897:
URL: https://github.com/apache/kafka/pull/10897


   Reduced severity for "skipping records" falling out of time windows/segments from "warn" to "debug" since this is, as mjsax called it on Slack, actually "regular processing", and we have metrics for skipped records anyway since Kafka Streams 2.0 (https://cwiki.apache.org/confluence/display/KAFKA/KIP-274%3A+Kafka+Streams+Skipped+Records+Metrics).
   
   Using severity "warn" or "info" results in lots of unnecessarily cluttered logs like this - even though the skipping is actually the intended processing behavior:
   {"@timestamp":"2021-06-17T19:04:44.194Z","@version":"1","message":"Skipping record for expired segment.","logger_name":"org.apache.kafka.streams.state.internals.AbstractRocksDBSegmentedBytesStore","thread_name":"prod.devices.manufacturing.pt.streamingetl.v3-5f937ad9-7f89-41c5-b4ba-591dabe838fd-StreamThread-1","level":"WARN","level_value":30000,"dd.service":"streaming-etl","dd.env":"prod","dd.span_id":"3790604313083202822","dd.trace_id":"2039260532201528974","dd.version":"1.0.0-20210616-master.4"}
   {"@timestamp":"2021-06-17T19:04:44.194Z","@version":"1","message":"Skipping record for expired segment.","logger_name":"org.apache.kafka.streams.state.internals.AbstractRocksDBSegmentedBytesStore","thread_name":"prod.devices.manufacturing.pt.streamingetl.v3-5f937ad9-7f89-41c5-b4ba-591dabe838fd-StreamThread-1","level":"WARN","level_value":30000,"dd.service":"streaming-etl","dd.env":"prod","dd.span_id":"3790604313083202822","dd.trace_id":"2039260532201528974","dd.version":"1.0.0-20210616-master.4"}
   {"@timestamp":"2021-06-17T19:04:44.194Z","@version":"1","message":"Skipping record for expired segment.","logger_name":"org.apache.kafka.streams.state.internals.AbstractRocksDBSegmentedBytesStore","thread_name":"prod.devices.manufacturing.pt.streamingetl.v3-5f937ad9-7f89-41c5-b4ba-591dabe838fd-StreamThread-1","level":"WARN","level_value":30000,"dd.service":"streaming-etl","dd.env":"prod","dd.span_id":"3790604313083202822","dd.trace_id":"2039260532201528974","dd.version":"1.0.0-20210616-master.4"}
   {"@timestamp":"2021-06-17T19:04:44.194Z","@version":"1","message":"Skipping record for expired segment.","logger_name":"org.apache.kafka.streams.state.internals.AbstractRocksDBSegmentedBytesStore","thread_name":"prod.devices.manufacturing.pt.streamingetl.v3-5f937ad9-7f89-41c5-b4ba-591dabe838fd-StreamThread-1","level":"WARN","level_value":30000,"dd.service":"streaming-etl","dd.env":"prod","dd.span_id":"3790604313083202822","dd.trace_id":"2039260532201528974","dd.version":"1.0.0-20210616-master.4"}
   {"@timestamp":"2021-06-17T19:04:44.194Z","@version":"1","message":"Skipping record for expired segment.","logger_name":"org.apache.kafka.streams.state.internals.AbstractRocksDBSegmentedBytesStore","thread_name":"prod.devices.manufacturing.pt.streamingetl.v3-5f937ad9-7f89-41c5-b4ba-591dabe838fd-StreamThread-1","level":"WARN","level_value":30000,"dd.service":"streaming-etl","dd.env":"prod","dd.span_id":"3790604313083202822","dd.trace_id":"2039260532201528974","dd.version":"1.0.0-20210616-master.4"}
   


-- 
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] xdgrulez commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   > @showuon I think one of the reasons to use `DEBUG` is no decrease the log messages which woiuld not be the case with `INFO`.
   
   Absolutely - we had a big influx of these WARN messages in our logs and I would prefer not to have them in INFO either. I mean it's just annoying ;-)
   
   (+ sorry for not having time yet to write the tests...)
   
   


-- 
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] mjsax commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Btw: I am just realizing that we actually log the `key` and thus leak user data into the logs. We must fix this. Thus, we should either switch to `TRACE` level (we consider `TRACE` ok, and have other places where we log user data in `TRACE`), or remove user data from the log message.


-- 
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] ableegoldman commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hey @xdgrulez , this PR has a number of test failures. It looks like there are quite a few tests that are verifying the existence of this specific message, and failing because the logs default to INFO. Can you look into those and then run the full set of streams tests once you think you've fixed everything to make sure no new failures have come up since then? 
   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 #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   FYI: I opened PR #10920 to improve the unit tests for the log messages for the other types of dropped records.


-- 
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] xdgrulez commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hi,
   
   I've fixed the tests now - on my local machine, the complete :streams:test suite is now working perfectly fine again :)
   
   Best regards,
   Ralph
   


-- 
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] ableegoldman commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   I completely agree that these are too frequent to warrant even being at INFO, however it's unfortunate to lose this information entirely as @showuon pointed out. Can we still keep track of the skipped records and instead just log a summary warning every 1,000 records (or something), like we do elsewhere?


-- 
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] xdgrulez commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hi @ableegoldman I think it would be good to have a less frequent output on e.g. INFO :) I won't have a lot of time to look into this in the near future, so please take this over :)


-- 
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] xdgrulez commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hi Matthias,
   
   I don't really have time but I'd like to get this done anyway ;)
   
   I think reopening a new PR would be more sensible... the change is too old.
   
   Best,
   Ralph
   
   
   Am So., 6. Feb. 2022 um 21:24 Uhr schrieb Matthias J. Sax <
   ***@***.***>:
   
   > @xdgrulez <https://github.com/xdgrulez> -- if you are still interested in
   > working on this, it would be great. The PR would needs to be
   > rebased/updated though (or just close this one an open a new PR?)
   >
   > —
   > Reply to this email directly, view it on GitHub
   > <https://github.com/apache/kafka/pull/10897#issuecomment-1030907208>, or
   > unsubscribe
   > <https://github.com/notifications/unsubscribe-auth/AUQWGA73SPNT352PYQ2LLC3UZ3KHBANCNFSM464IJVUQ>
   > .
   > Triage notifications on the go with GitHub Mobile for iOS
   > <https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675>
   > or Android
   > <https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub>.
   >
   > You are receiving this because you were mentioned.Message ID:
   > ***@***.***>
   >
   


-- 
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] mjsax closed pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

Posted by GitBox <gi...@apache.org>.
mjsax closed pull request #10897:
URL: https://github.com/apache/kafka/pull/10897


   


-- 
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] xdgrulez commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hi,
   
   will do that as soon as I have some time - and sorry for not finding time yet…
   
   If anyone else would have some more time on her/his hand - you basically just would have to spot all tests checking for the respective warn log messages and change them to debug…
   
   Best, Ralph
   
   > Am 28.07.2021 um 23:27 schrieb A. Sophie Blee-Goldman ***@***.***>:
   > 
   > 
   > Hey @xdgrulez , this PR has a number of test failures. It looks like there are quite a few tests that are verifying the existence of this specific message, and failing because the logs default to INFO. Can you look into those and then run the full set of streams tests once you think you've fixed everything to make sure no new failures have come up since then?
   > Thanks!
   > 
   > —
   > You are receiving this because you were mentioned.
   > Reply to this email directly, view it on GitHub, or unsubscribe.
   


-- 
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] mjsax commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Thanks for getting back. Closing this PR.


-- 
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] mjsax commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   @xdgrulez -- if you are still interested in working on this, it would be great. The PR would needs to be rebased/updated though (or just close this one an open a new PR?)


-- 
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 #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   @showuon I think one of the reasons to use `DEBUG` is no decrease the log messages which woiuld not be the case with `INFO`.


-- 
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] ableegoldman commented on pull request #10897: MINOR: Reduced severity for "skipping records" falling out of time windows

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


   Hey @xdgrulez , sorry for the delay! Somehow your last response slipped past me. It seems like there have been some conflicting changes merged recently, can you rebase/pull to fix these conflicts?
   
   Also, WDYT about [this](https://github.com/apache/kafka/pull/10897#issuecomment-868900284)? I've actually seen a number of users asking questions about these log lines recently, so I wonder if it might still be useful to include them higher than DEBUG, albeit infrequently.


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