Sending/receiving duplicate events

[leggetter]

Describe the bug

Upon publishing a single event, a destination is receiving duplicate events. I think this is because of some internal error that's triggering a retry.

Full details. I'm not sure if I'll be able to reproduce, but will try again after this report.

Version: v0.1.0-alpha.7

Here's what I did:

1. Created a new destination of type webhook in the UI.
2. Published an event using the API
3. Endpoint received the event, signed the payload, and accepted it. Responded with 200.
4. The event was received again and again...

The Outpost log shows the following:

postgres-1  | 2025-03-14 17:04:25.761 UTC [147892] STATEMENT:  copy "events" ( "id", "tenant_id", "destination_id", "time", "topic", "eligible_for_retry", "data", "metadata" ) from stdin binary;
log-1       | {"level":"info","ts":1741971865.8142154,"caller":"logmq/messagehandler.go:31","msg":"logmq handler"}
log-1       | {"level":"info","ts":1741971875.7632256,"caller":"log/log.go:151","msg":"processing batch","message_count":1}
postgres-1  | 2025-03-14 17:04:35.766 UTC [147892] ERROR:  duplicate key value violates unique constraint "events_default_pkey"
postgres-1  | 2025-03-14 17:04:35.766 UTC [147892] DETAIL:  Key ("time", id)=(2025-03-14 17:02:21.111495+00, f30f97d6-a26f-44cb-bffd-1eb9f454bb4e) already exists.
log-1       | {"level":"error","ts":1741971875.7668989,"caller":"log/log.go:186","msg":"failed to insert events","error":"ERROR: duplicate key value violates unique constraint \"events_default_pkey\" (SQLSTATE 23505)","event_count":1,"stacktrace":"github.com/hookdeck/outpost/internal/services/log.makeBatcher.func1\n\t/home/runner/work/outpost/outpost/internal/services/log/log.go:186\ngithub.com/mikestefanello/batcher.(*Batcher[...]).jobWorker\n\t/home/runner/go/pkg/mod/github.com/mikestefanello/batcher@v0.1.0/batcher.go:107"}
postgres-1  | 2025-03-14 17:04:35.766 UTC [147892] CONTEXT:  COPY events, line 1
postgres-1  | 2025-03-14 17:04:35.766 UTC [147892] STATEMENT:  copy "events" ( "id", "tenant_id", "destination_id", "time", "topic", "eligible_for_retry", "data", "metadata" ) from stdin binary;
log-1       | {"level":"info","ts":1741971875.7805002,"caller":"logmq/messagehandler.go:31","msg":"logmq handler"}
log-1       | {"level":"info","ts":1741971885.7685466,"caller":"log/log.go:151","msg":"processing batch","message_count":1}
log-1       | {"level":"error","ts":1741971885.7699602,"caller":"log/log.go:186","msg":"failed to insert events","error":"ERROR: duplicate key value violates unique constraint \"events_default_pkey\" (SQLSTATE 23505)","event_count":1,"stacktrace":"github.com/hookdeck/outpost/internal/services/log.makeBatcher.func1\n\t/home/runner/work/outpost/outpost/internal/services/log/log.go:186\ngithub.com/mikestefanello/batcher.(*Batcher[...]).jobWorker\n\t/home/runner/go/pkg/mod/github.com/mikestefanello/batcher@v0.1.0/batcher.go:107"}
postgres-1  | 2025-03-14 17:04:45.769 UTC [147892] ERROR:  duplicate key value violates unique constraint "events_default_pkey"
postgres-1  | 2025-03-14 17:04:45.769 UTC [147892] DETAIL:  Key ("time", id)=(2025-03-14 17:02:21.111495+00, f30f97d6-a26f-44cb-bffd-1eb9f454bb4e) already exists.
postgres-1  | 2025-03-14 17:04:45.769 UTC [147892] CONTEXT:  COPY events, line 1
postgres-1  | 2025-03-14 17:04:45.769 UTC [147892] STATEMENT:  copy "events" ( "id", "tenant_id", "destination_id", "time", "topic", "eligible_for_retry", "data", "metadata" ) from stdin binary;

Expected behavior
The event was successfully received so should not be resent.

[alexluong]

I see the errors in the log service but what about the delivery service? The log doesn't explain what triggers the redelivery.

[leggetter]

@alexluong so it wasn't this that triggered the error:

2025-03-14 17:04:45.769 UTC [147892] ERROR: duplicate key value violates unique constraint "events_default_pkey"

I may have deleted the volumes where this was occurring. So, if what you have here isn't enough to track the problem down, we can keep this open for now and see if it happens again. If it does, I'll make sure I get the delivery logs. But, as mentioned, the delivery succeeds.

[alexluong]

@leggetter no, that happens in the log service which should not impact the event delivery. This happens because the event is being redelivered multiple times. It's a bug indeed that we should fix, but it's not the cause of duplicate events.

[fmvilas]

@leggetter @alexluong Is this issue still relevant? I haven't seen this behavior so far 🤔

[leggetter]

Obviously an old one and I haven't seen it since.

[fmvilas]

I'm closing it for now then. Feel free to reopen if you see it again.