`dedupe` hides events that occur continuously

[ilinas]

A note for the community

• Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
• If you are interested in working on this issue or have submitted a pull request, please leave a comment

Use Cases

We have some services that can generate an enormous amount of log events in case of failures, and we are using dedupe to protect our log aggregators from being overwhelmed.

However in cases where a message is repeated continuously, e.g. an application keeps logging the same error, dedupe will only let the message through once, and never again. If you miss the initial message, and look at the logs at a later date, you will not find any log events, erroneously believing that nothing of importance is happening. Whereas in reality the application may be desperately spewing out thousands of error messages.

Consider the following situation:

sources:
  log_generator:
    type: demo_logs
    format: shuffle
    lines:
      - 'greetings'
      - 'welcome'
      - 'hello'
    interval: 0.2

transforms:
  dedupe:
    type: dedupe
    inputs:
      - log_generator
    fields:
      match:
        - message

sinks:
  output:
    type: console
    inputs:
      - dedupe
    encoding:
      codec: json

This will let the event though only once, and never again:

{"host":"localhost","message":"hello","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:33:57.977945319Z"}
{"host":"localhost","message":"greetings","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:33:58.179360057Z"}
{"host":"localhost","message":"welcome","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:33:58.778797868Z"}

Attempted Solutions

We worked it around by adding a truncated timestamp to log events to get them to output at least once a second:

sources:
  log_generator:
    type: demo_logs
    format: shuffle
    lines:
      - 'greetings'
      - 'welcome'
      - 'hello'
    interval: 0.2

transforms:
  add_secs_timestamp:
    type: remap
    inputs:
      - log_generator
    source: |
      .secs_timestamp = to_string!(to_unix_timestamp!(.timestamp, "seconds"))

  dedupe:
    type: dedupe
    inputs:
      - add_secs_timestamp
    fields:
      match:
        - message
        - secs_timestamp

sinks:
  output:
    type: console
    inputs:
      - dedupe
    encoding:
      codec: json

This will make sure that we see the event at least once a second:

{"host":"localhost","message":"hello","secs_timestamp":"1744188513","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:33.446753593Z"}
{"host":"localhost","message":"welcome","secs_timestamp":"1744188513","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:33.647865211Z"}
{"host":"localhost","message":"hello","secs_timestamp":"1744188514","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:34.047107454Z"}
{"host":"localhost","message":"welcome","secs_timestamp":"1744188514","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:34.246730722Z"}
{"host":"localhost","message":"greetings","secs_timestamp":"1744188515","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:35.046117586Z"}
{"host":"localhost","message":"hello","secs_timestamp":"1744188515","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:35.246558373Z"}
{"host":"localhost","message":"greetings","secs_timestamp":"1744188516","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:36.046720858Z"}
{"host":"localhost","message":"welcome","secs_timestamp":"1744188516","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:36.246820751Z"}
{"host":"localhost","message":"hello","secs_timestamp":"1744188517","service":"vector","source_type":"demo_logs","timestamp":"2025-04-09T08:48:37.046530422Z"}

We also considered the reduce transformation, but found it hard to use in a generic manner, as aggregation changes the log message format, which we do not want.

Proposal

It would be useful to have a way to limit how long the events spend in the deduplication queue before letting them through.

Two options spring to mind:

1. Let an event though every max_duplicates number of events.
2. Have maximum time expire_after_ms an event is kept in the queue the just like in dedupe.

transform:
  dedupe:
    type: dedupe
    inputs:
      - logs
    max_duplicates: 100
    expire_after_ms: 1000
    fields:
      match:
        - message

References

No response

Version

No response

[wjordan]

1. You can consider the sample transform, which is similar to dedupe and allows you to specify a rate at which events are forwarded (and the rest dropped).
2. You can control the output format of reduce at a granular level with merge_strategies, so you can probably set up a merge strategy appropriate for your data that preserves the original log message format.

[ilinas]

Thanks @wjordan, I think sample could work in our case. The problem with reduce is that we cannot control merge strategies for messages that have variable fields as per #18239.

[ilinas]

However I believe there still may be a potential issue here with dedupe and its rather unintuitive behavior. When the rate of duplicates is low enough, and it is intermixed with other messages, it works pretty well. However when it goes high enough, the events can get completely hidden.

Another example of the issue:

We were using dedupe on HTTP access logs to de-duplicate by path. We have a lot of calls to endpoints like /api/status that are not very interesting most of the time. However once a service got into a bad state and started calling /api/status multiple times a second, and it lasted for several days. However when we looked at recent logs there were no calls to /api/status, because dedupe would keep pushing them back up in the queue, and never let them through. So it looked like there was no traffic to /api/status at all. We have since switched to reduce for this particular use case.

[pront]

We were using dedupe on HTTP access logs to de-duplicate by path. We have a lot of calls to endpoints like /api/status that are not very interesting most of the time. However once a service got into a bad state and started calling /api/status multiple times a second, and it lasted for several days. However when we looked at recent logs there were no calls to /api/status, because dedupe would keep pushing them back up in the queue, and never let them through. So it looked like there was no traffic to /api/status at all. We have since switched to reduce for this particular use case.

Did you take a look at the emitted metrics? Any errors or dropped events?

[ilinas]

Did you take a look at the emitted metrics? Any errors or dropped events?

As far as I remember, you could see events being dropped in internal_metrics as one would expect.

The issue is how dedupe works by design: the higher the duplicate volume, the less likely you are to see the events at all, because they will be constantly pushed back in the queue. In my example with demo_logs, you could run it for an hour or a month, you will only see the events being emitted once. It is not immediately obvious that this will happen, and I would argue that it is rarely desirable.

I believe there should be a way to limit how many duplicates are filtered before an event is finally released from the queue.