Is Message header id unique?

[sarahjduan]

We use spring integration <si-jdbc:inbound-channel-adapter> to retrieve messages from a staging table (25 rows/poll). After split and transform, each record will be saved as an event to an event table. One of the fields we save to the event table is UUID, which is from the message header id (@Header("id")). We found records with duplicate UUID in the event table. Most of them are 2 in a pair with the same creation time stamp. By looking at other columns in the table, we can tell they are different events. My understanding is the message header id is an UUID, which should not give duplicates. Please help.

[Gary Russell]

Yes, message id is unique - are you sure your code is thread-safe?

[sarahjduan]

I turned on the spring integration package to DEBUG and see the ids were different in org.springframework.integration.transformer.Messag eTransformingHandler. But when they reached our transform method, they became the same. Here is the debug. We use WAS workmanager and the debug shows thread 5 and thread 2:

2013-01-17 13:01:12,923 DEBUG [WorkManager.: 5] org.springframework.integration.filter.MessageFilt er - org.springframework.integration.filter.MessageFilt er@1de50f84 received message: [Payload={EVENT_STAGING_ID=661162467, ][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=3, id=eca7d75a-0455-4423-a0d4-d85c141db8c5, correlationId=312f3cbe-2c53-4888-a17c-797d8dc0aeef}]
2013-01-17 13:01:12,923 DEBUG [WorkManager.: 2] org.springframework.integration.filter.MessageFilt er - org.springframework.integration.filter.MessageFilt er@1de50f84 received message: [Payload={EVENT_STAGING_ID=661162463, ][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=24, id=fc650c7a-56cf-44e5-b703-a0b33c35315d, correlationId=15e8c402-a03a-42ef-b05b-07298c310923}]
2013-01-17 13:01:12,923 DEBUG [WorkManager.: 2] com.util.EventValidation - filterEvent :{EVENT_STAGING_ID=661162463,}
2013-01-17 13:01:12,923 DEBUG [WorkManager. 5] com.util.EventValidation - filterEvent :{EVENT_STAGING_ID=661162467,}
2013-01-17 13:01:12,924 DEBUG [WorkManager. 2] org.springframework.integration.filter.MessageFilt er - handler 'org.springframework.integration.filter.MessageFil ter@1de50f84' sending reply Message: [Payload={EVENT_STAGING_ID=661162463}][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=24, id=fc650c7a-56cf-44e5-b703-a0b33c35315d, correlationId=15e8c402-a03a-42ef-b05b-07298c310923}]
2013-01-17 13:01:12,924 DEBUG [WorkManager. 5] org.springframework.integration.filter.MessageFilt er - handler 'org.springframework.integration.filter.MessageFil ter@1de50f84' sending reply Message: [Payload={EVENT_STAGING_ID=661162467}][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=3, id=eca7d75a-0455-4423-a0d4-d85c141db8c5, correlationId=312f3cbe-2c53-4888-a17c-797d8dc0aeef}]
2013-01-17 13:01:12,924 DEBUG [WorkManager. 2] org.springframework.integration.transformer.Messag eTransformingHandler - org.springframework.integration.transformer.Messag eTransformingHandler@1de533b4 received message: [Payload={EVENT_STAGING_ID=661162463}][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=24, id=fc650c7a-56cf-44e5-b703-a0b33c35315d, correlationId=15e8c402-a03a-42ef-b05b-07298c310923}]
2013-01-17 13:01:12,924 DEBUG [WorkManager. 5] org.springframework.integration.transformer.Messag eTransformingHandler - org.springframework.integration.transformer.Messag eTransformingHandler@1de533b4 received message: [Payload={EVENT_STAGING_ID=661162467}][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672923, sequenceNumber=3, id=eca7d75a-0455-4423-a0d4-d85c141db8c5, correlationId=312f3cbe-2c53-4888-a17c-797d8dc0aeef}]
2013-01-17 13:01:12,924 DEBUG [WorkManager. 2] com.util.EventTransformer - transformEvent-fc650c7a-56cf-44e5-b703-a0b33c35315d
2013-01-17 13:01:12,924 DEBUG [WorkManager. 2 ] org.springframework.integration.transformer.Messag eTransformingHandler - handler 'org.springframework.integration.transformer.Messa geTransformingHandler@1de533b4' sending reply Message: [Payload=com.Event@1dd3451e][Headers={sequenceSize=25, history=resultSetChannel, timestamp=1358445672924, sequenceNumber=24, id=edc6c6c5-a837-4904-a84a-79696888aabd, correlationId=15e8c402-a03a-42ef-b05b-07298c310923}]
2013-01-17 13:01:12,924 DEBUG [WorkManager. 5] com.util.EventTransformer - transformEvent-fc650c7a-56cf-44e5-b703-a0b33c35315d


Here is my configuration and transform method:

<si:chain id="jdbcChain" input-channel="resultSetChannel" output-channel="eventRoutingChannel">
<si:splitter/>
<si:filter ref="eventValidationFilter" method="isValidEvent" discard-channel="poisonChannel" />
<si:transformer ref="eventTransformer" method="transformEvent"/>
</si:chain>

<bean id="eventTransformer"
class="com.util.eventTransformer" />


public Event transformEvent(HashMap resultsetMap, @Header("id") String id) throws Exception{
logger.debug("transformEvent-{}", id);
-----

}

[Cleric]

Hi!
Sorry, now it's difficult to read your post. Please, highlight problems.
At a glance you mean MessageFilter, which really doesn't do anything with Message. Look at this as Validator.
So, you see here not the same Message id, but the same Message object.
By the way 'empty' transformer will do the same, if pass to him entire Message.

HTH,
Artem

[Gary Russell]

As I said, my best guess is your code is not thread-safe - you didn't show us the code in your transformer.

Clearly from the log, the two threads invoke the transformer with different messages at the same instant...

...12,924...[WorkManager. 2] ...MessageTransformingHandler@... [Payload={EVENT_STAGING_ID=661162463}...  sequenceNumber=24, id=fc650c7a-56cf-44e5-b703-a0b33c35315d, correlationId=15e8c402-a03a-42ef-b05b-07298c310923}]
...12,924...[WorkManager. 5] ...MessageTransformingHandler@... [Payload={EVENT_STAGING_ID=661162467}... sequenceNumber=3, id=eca7d75a-0455-4423-a0d4-d85c141db8c5, correlationId=312f3cbe-2c53-4888-a17c-797d8dc0aeef}]

But your transformer reports they got the same id...

2013-01-17 13:01:12,924 DEBUG [WorkManager. 2] com.util.EventTransformer - transformEvent-fc650c7a-56cf-44e5-b703-a0b33c35315d
2013-01-17 13:01:12,924 DEBUG [WorkManager. 5] com.util.EventTransformer - transformEvent-fc650c7a-56cf-44e5-b703-a0b33c35315d

[sarahjduan]

The Debug that prints the id is the first line in the transformer transform method. We use @Header("id") to get the message id. It seems to me that when the id was passed to transformEvent method, it already got mixed up with another message. Please see the following transformEvent code. Thanks so much for the help.

public Event transformEvent(HashMap resultsetMap, @Header("id") String id) throws Exception{
logger.debug("transformEvent-{}", id);
Event event = new Event();
event.setId(id);

// do other transform
return event;

}

[Gary Russell]

Hmmm... what version of Spring Integration are you using?

[sarahjduan]

Thanks, Gary. We use Spring Integration 2.1.2.

[Gary Russell]

I have reproduced your problem - I am not sure what's going on yet, but as a work-around, you could change your method signature to

public Event transformEvent(Message<Map<?,?>> message) throws Exception {
    Map resultsetMap = message.getPayload();
    String id = message.getHeaders().getId().toString();
...

It looks like the problem is during extraction of the message headers, when matching the method parameters; it doesn't seem to occur when passing the complete message.

[Gary Russell]

It turns out to be a concurrency problem in the framework, when converting the id header (which is a UUID) to a String.

https://jira.springsource.org/browse/INT-2889

Another work-around is to use the following...

public Event transformEvent(HashMap resultsetMap, @Header("id") UUID uuid) throws Exception{
    String id = uuid.toString();
...

...because this avoids the conversion.

I apologize for suggesting the thread-safety problem was in your code.