bug(reducer transform): Sum merger does not sum in some cases

[Hoverbear]

Sometimes it just doesn't sum.

Reproduction:

data_dir = "var"

[transforms.reducer]
  type = "reduce"
  inputs = ["database_log"]
  identifier_fields = ["transaction_id"]
  merge_strategies.transaction_id = "discard"
  merge_strategies.stop_summing = "discard"
  merge_strategies.sum_this = "sum"
  ends_when.type = "check_fields"
  ends_when."stop_summing.eq" = true

[[tests]]
  name = "Reducer"

  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields.transaction_id = 1
    log_fields.sum_this = 1
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 1, "sum_this" = 1 }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 2, "sum_this" = 24 }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 1, "stop_summing" = true }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 2, "sum_this" = 24 }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 3, "sum_this" = 2 }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 3, "sum_this" = 2, "note" = "This one will expire after a configured time" }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 1, "sum_this" = 1, "note" = "This is a new one!" }
  [[tests.inputs]]
    insert_at = "reducer"
    type = "log"
    log_fields = { "transaction_id" = 1, "stop_summing" = true }

  [[tests.outputs]]
    extract_from = "reducer"
  [[tests.outputs.conditions]]
    "transaction_id.eq" = 1
    "sum_this.eq" = 2
  [[tests.outputs.conditions]]
    "transaction_id.eq" = 2
    "sum_this.eq" = 48
  [[tests.outputs.conditions]]
    "transaction_id.eq" = 3
    "sum_this.eq" = 2

hoverbear@OBSIDIAN:/git/timberio/vector$ ./target/debug/vector test test.toml 
Jul 15 15:00:35.567  INFO vector: Log level "info" is enabled.
Running test.toml tests
test test.toml: Reducer ... failed

failures:

--- test.toml ---

test 'Reducer':

check transform 'reducer' failed conditions:
  condition[1], payload[0]: predicates failed: [ transaction_id.eq: 2, sum_this.eq: 48 ]
  condition[1], payload[1]: predicates failed: [ transaction_id.eq: 2, sum_this.eq: 48 ]
  condition[2], payload[0]: predicates failed: [ transaction_id.eq: 3, sum_this.eq: 2 ]
  condition[2], payload[1]: predicates failed: [ transaction_id.eq: 3 ]
payloads (events encoded as JSON):
  inputs:
    {"message":"","stop_summing":true,"timestamp":"2020-07-15T22:00:35.596734179Z","transaction_id":1}
    {"message":"","note":"This is a new one!","sum_this":1,"timestamp":"2020-07-15T22:00:35.596695480Z","transaction_id":1}
    {"message":"","note":"This one will expire after a configured time","sum_this":2,"timestamp":"2020-07-15T22:00:35.596652782Z","transaction_id":3}
    {"message":"","sum_this":2,"timestamp":"2020-07-15T22:00:35.596626982Z","transaction_id":3}
    {"message":"","sum_this":24,"timestamp":"2020-07-15T22:00:35.596597783Z","transaction_id":2}
    {"message":"","stop_summing":true,"timestamp":"2020-07-15T22:00:35.596570384Z","transaction_id":1}
    {"message":"","sum_this":24,"timestamp":"2020-07-15T22:00:35.596530485Z","transaction_id":2}
    {"message":"","sum_this":1,"timestamp":"2020-07-15T22:00:35.596471387Z","transaction_id":1}
    {"message":"","sum_this":1,"timestamp":"2020-07-15T22:00:35.595756910Z","transaction_id":1}
  outputs:
    {"message":"","note":"This is a new one!","stop_summing":true,"sum_this":1,"timestamp":"2020-07-15T22:00:35.596695480Z","timestamp_end":"2020-07-15T22:00:35.596734179Z","transaction_id":1}
    {"message":"","stop_summing":true,"sum_this":2,"timestamp":"2020-07-15T22:00:35.595756910Z","timestamp_end":"2020-07-15T22:00:35.596570384Z","transaction_id":1}

[Hoverbear]

Blocks #2961

[lukesteensen]

This looks like expected behavior to me. You flush "transaction_id" = 1 twice, which matches the outputs listed.

The unit tests don't have a way to simulate time to expire the other two transactions, and they are not built in a way that the topology is flushed for each test. Those would both be useful additions to the testing functionality, but I don't think they indicate any issue with the reduce transform.

Please reopen if any of that sounds incorrect!

[Hoverbear]

Confirming this was a red herring: