Hi,

I just wanted to share how we misinterpreted logs from Streams at the INFO
level. Version 0.10.1.1, I think it's the same for 0.10.2.0.

So, we configured `commit.interval.ms` and `cache.max.bytes.buffering`, and
we expected to always reach the commit interval before the maximum bytes.
It was confirmed by looking at the logs the commit interval actually
triggered commits. No logs about the maximum bytes.

But then I noticed in our monitoring graphs and by consuming output topics
that the rate of messages was way too high (thanks to pv[1]).

I checked the code of Streams to write a kinda "sequence diagram" to see
what was logged and at what level.

For `commit.interval.ms`:
- StreamThread#maybeCommit does an INFO recalling the configured duration
- then StreamThread#commitOne does one INFO per task.
- then NamedCache#flush announces the flushes at DEBUG level.

For `cache.max.bytes.buffering`:
- ThreadCache#maybeEvict does a TRACE (?!?) to announce that the cache is
too big
- then NamedCache#flush announces the flushes at DEBUG level.

So I think it makes the logs not exhaustive enough concerning the writes to
States + Changelog topics +  Output topics (Processor forwards). Thus logs
are easily misinterpreted.

Should I file a JIRA ?

[1] https://linux.die.net/man/1/pv

- Nicolas

Reply via email to