pkg/chunkenc: ignore duplicate lines pushed to a stream

[rfratto]

This commit changes the behavior of appending to a stream to ignore an incoming line if its timestamp and contents match the previous line received. This should reduce the chances of ingesters storing duplicate log lines when clients retry push requests whenever a 500 is returned.

Fixes #1517.

[slim-bean]

instead of ignoring, should we consider fudging the timestamp?

[slim-bean]

in addition to not applying to flushed chunks, it also doesn't apply to the last entry in the previous block, though this we could probably address?

[rfratto]

I'm not sure I understand why we'd want to do that? Consider what happens today:

1. A distributor pushes to ingesters A, B, C.
2. Ingester A accepts the log lines.
3. Ingesters B and C have some intermittent 500 error.
4. This 500 error is propagated back to Promtail, who backs off and retries the request.
5. B and C now accept the new log lines.
6. A returns OutOfOrder errors for all lines except for the most recent, which it accepts as valid and appends to the stream, even though it already has it.

There's a few issues with this:

1. It's a duplicate log line that will show up in query results (I think, since it's coming from one ingester)
2. It causes the chunks for A, B, and C to be desynced as A has one more entry than B and C. Two different chunks will be flushed to the backing store.

[rfratto]

in addition to not applying to flushed chunks, it also doesn't apply to the last entry in the previous block, though this we could probably address?

We could, I didn't bother because it requires decompressing the entire chunk. It probably wouldn't be required that often, but it sounds like a non-zero performance hit, right?

[slim-bean]

there is a different case here, the client sends two different log lines with the same timestamp, this is the case were I think we could consider fudging the timestamp for them

[rfratto]

yeah, I don't know, that sounds hard to get right. What if all their logs are only precise to the second and they send 50 log lines with the same timestamp? We'd have to track the fudged timestamp over time and keep that running across cut chunks.

[slim-bean]

i think this is why nobody has addressed this before, currently we would store these logs for them, this would start dropping them.

[rfratto]

this only drops the lines if the content matches the last stored line, though?

[rfratto]

fwiw, Cortex drops all duplicates with the same timestamp, even if the value doesn't match. i don't think that's the right thing for us to do, though

[slim-bean]

this only drops the lines if the content matches the last stored, though?

ah right, yeah this would be beneficial and less risky/impacting

[rfratto]

after talking to Ed, I'm going to enhance this commit to work across flushes and cut chunks by tracking the most recently written line and timestamp per stream.

[rfratto]

@slim-bean PTAL, this should cover more edge cases better now

[slim-bean]

LGTM!

[maxdialpad]

We're running into a similar issue, except the exact same timestamp applies to two legitimately different log lines.
For example, I have my_service, which is outputting something like this in my_service.log:

2022-03-28T00:00:00.000Z 1Starting a new channel
2022-03-28T00:00:00.000Z 2Doing something else. Yes this is the exact same timestamp
2022-03-28T00:00:00.015Z 3Doing some other thing

In Loki, we may see the logs ordered like so

2022-03-28T00:00:00.000Z 2Doing something else. Yes this is the exact same timestamp
2022-03-28T00:00:00.000Z 1Starting a new channel
2022-03-28T00:00:00.015Z 3Doing some other thing

I think this could be solved in a more traditional index-heavy log aggregator by incorporating a offset label (or index) that can essentially act as a tie-breaker in these scenarios. The offset is the byte offset in the original log file at which a given log line starts.
With Loki, that's tough. The offset label would obviously be incredibly diverse in cardinality, so I don't think that would work smoothly.