Marking event as completed fails silently

[maciejwalkowiak]

When event serialization is misconfigured, it may happen that the serialized_event stored in the event_publication table will have slightly different value than the serialized event used in EventPublicationRepository#markCompleted. As a result, even though the event was processed successfully, it is never marked as processed.

This is a corner case, but since I've run into it, it may happen that others run into this issue too.

Here's the repository that reproduces the issue: https://github.com/maciejwalkowiak/modulith-mark-as-processed-issue

There are two classes to look at and I tried to explain what happens with comments:

• https://github.com/maciejwalkowiak/modulith-mark-as-processed-issue/blob/main/src/main/java/com/example/ModulithMarkAsProcessedIssueApplication.java
• https://github.com/maciejwalkowiak/modulith-mark-as-processed-issue/blob/main/src/test/java/com/example/ModulithMarkAsProcessedIssueApplicationTests.java

Once you run the test, you'll see in logs where's the problem.

I believe EventPublicationRepository#markCompleted should throw an exception if no rows have been updated. This would make our serialization mistake obvious much sooner.

[odrotbohm]

Do you think a EmptyResultDataAccessException would be appropriate, or shall we rather create a custom one?

[maciejwalkowiak]

I can't think of any reason why it wouldn't be appropriate.

[odrotbohm]

Testing a fix for this seems more elaborate than originally anticipated. Removing this from the RC1. I think we should be able to ship it in an upcoming bug fix release, though.

[maciejwalkowiak]

Thinking it through again - I think fail fast strategy would work better here. Ideally event should be not processed at all if its it cannot be marked as completed after successful processing - in this case it means that if JSON -> object -> JSON does not produce same JSON as input, the exception should be thrown before processing happens.

Otherwise, an event may be processed multiple times before the serialization issue is addressed by developers.

Other than quite obvious mistake like one provided in example, the difference between two JSON objects can happen if event is not completed, new field gets added to event payload class, new deployment, and then reprocessing is triggered. Perhaps the ObjectMapper provided to JacksonEventSerializer should be configured to skip null fields and empty collections.

[cmetzlerhg]

We ran into the same issue today and it took us quite a while to figure out, what happened.

In our case we could see, that the date formats were different in the serialized event in the database vs. the serialized event in the UPDATE statement.

In the event publication registry we have the following format in our serialized event:

"createdAt" : "2024-06-20T09:20:16.805066546+02:00"

But when the markCompleted method it was serialized as:

"createdAt" : "2024-06-20T07:20:16.805066546Z"

So in that case the update fails, and the event is replayed but never marked as completed. We're now going back to just send IDs in events instead of event carried state transfer. Maybe the resolution strategy to find an event should be improved (or be customizable).

[mschaidinger]

We ran into the same issue today and it took us quite a while to figure out, what happened.

In our case we could see, that the date formats were different in the serialized event in the database vs. the serialized event in the UPDATE statement.

In the event publication registry we have the following format in our serialized event:

"createdAt" : "2024-06-20T09:20:16.805066546+02:00"

But when the markCompleted method it was serialized as:

"createdAt" : "2024-06-20T07:20:16.805066546Z"

So in that case the update fails, and the event is replayed but never marked as completed. We're now going back to just send IDs in events instead of event carried state transfer. Maybe the resolution strategy to find an event should be improved (or be customizable).

Thank you so much for pointing me in that direction. It would have taken me ages to locate the problem. I fixed it with Jackson configuration for the time being:

spring.jackson.deserialization.adjust-dates-to-context-time-zone=false

[MakotoTheKnight]

We ran into the same issue today and it took us quite a while to figure out, what happened.

In our case we could see, that the date formats were different in the serialized event in the database vs. the serialized event in the UPDATE statement.

In the event publication registry we have the following format in our serialized event:

"createdAt" : "2024-06-20T09:20:16.805066546+02:00"

But when the markCompleted method it was serialized as:

"createdAt" : "2024-06-20T07:20:16.805066546Z"

So in that case the update fails, and the event is replayed but never marked as completed. We're now going back to just send IDs in events instead of event carried state transfer. Maybe the resolution strategy to find an event should be improved (or be customizable).

I ran into this too, and debugging it is incredibly confusing, since it goes into the database with the right timezone data, but comes out of the database assuming Zulu time.

I think the right solution for this would be to use the UUID as the field to match (since that is the key in the database), as opposed to a timestamp (which is at the mercy of how it is deserialized).

[dustinsand]

We've encountered this issue in two scenarios:

1. Event mutation post-publication: The event is modified after being published, resulting in serialization discrepancies that prevent the event from being marked as complete. While events should ideally be immutable, enforcing this in practice can be challenging to catch during code reviews.

2. Serialization changes affecting retry logic: Events may remain incomplete due to expected processing failures. However, when a new release alters the serialization, our retry mechanism can enter an indefinite loop, republishing the failed event until it reaches the maximum retry limit. This type of serialization change is particularly difficult to detect during code reviews.

That said, I believe the Modulith 1.3 release addresses this issue with the "Completing Event Publications by Identifier" enhancement. I'm currently testing the 1.3 release to verify it resolves my above scenarios. Can we confirm if this resolves the problem and close this issue?

[maciejwalkowiak]

@dustinsand after upgrading to Modulith 1.3.1, the issue remains https://github.com/maciejwalkowiak/modulith-mark-as-processed-issue

[dustinsand]

@maciejwalkowiak I believe your issue remains due to an issue I recently opened, PersistentApplicationEventMulticaster.resubmitIncompletePublications does not update the event as completed. resubmitIncompletePublications(...) is not using the new Completing Event Publications by Identifier update in Modulith 1.3.1+

The normal flow of ApplicationEventPublisher.publish(...) is using the new Completing Event Publications by Identifier in my testing.