Search code examples
javaoracleapache-cameljmsoracle-aq

Camel consuming message from queue but fails to recreate it


I have a problem where my counterpart is placing messages on a JMS TEXT queue on Oracle (some custom application not using java) and I am to pick it up. The route is very simple:

<!--Receive data from oracle queue -->
<route id="ReadFromQueue" autoStartup="true">
    <from uri="oracleQueue:queue:SCAQUSER.SCD2TC?jmsMessageType=Text" />
    <log message="Picked up message ${body}" />
    <to uri="file:/e:/Tradechannel/in" />
</route>

The connection is up and running and my route responds immediately when a message is placed in the queue. When running the code with oracle.jms.traceLevel=6 everything seems to be working correctly in my eyes at least.

Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  Timeout: 1 seconds.  Iterations: 1 Interval: 120 Last interval: 1
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  wait time: 1
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  payload type:SYS.AQ$_JMS_TEXT_MESSAGEpayload type code:2002
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.getCompliant:  Session :false
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsUtil.getTextData:  entry
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsUtil.getTextData:  textLen: 288
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsUtil.getTextData:  exit
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  text_message retrieved
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  set AQ enqueue time as 1576249545000
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  msg_id: 999832415E09038AE0535C35EB751E09 corrid: null priority: 1
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  msg_delay(secs): 0
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  exptime(secs): -1
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  attempts: 0
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  exception queue: null
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.getCompliant:  Session :false
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  recv_time: 1576746524523
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.inGlobalTransRechecked:  entry
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.inGlobalTransRechecked:  oracle.jms.useEmulatedXA is on
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] EmulatedXAHandler.inGlobalTrans:  entry, reCheck=true
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] EmulatedXAHandler.checkForGlobalTxn:  entry
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] EmulatedXAHandler.inGlobalTrans:  exit
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.inGlobalTransRechecked:  exit
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsSession.restartConsumers:  entry
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.doCommit:  acknowledged one message received by committing the database connection
Camel (camel-1) thread #4 - JmsConsumer[SCAQUSER.SCD2TC] [Thu Dec 19 10:08:44 CET 2019] AQjmsConsumer.jdbcDequeue:  exit

The message is removed from the queue but in my application log I get an error...

2019-12-19 10:08:44:554 o.a.c.c.jms.EndpointMessageListener WARN  - Execution of JMS message listener failed. Caused by: [org.apache.camel.RuntimeCamelException - JMSXGroupSeq]
org.apache.camel.RuntimeCamelException: JMSXGroupSeq
    at org.apache.camel.component.jms.JmsBinding.extractHeadersFromJms(JmsBinding.java:225)
    at org.apache.camel.component.jms.JmsMessage.populateInitialHeaders(JmsMessage.java:235)
    at org.apache.camel.impl.DefaultMessage.createHeaders(DefaultMessage.java:258)
    at org.apache.camel.component.jms.JmsMessage.ensureInitialHeaders(JmsMessage.java:220)
    at org.apache.camel.component.jms.JmsMessage.getHeader(JmsMessage.java:170)
    at org.apache.camel.impl.DefaultMessage.getHeader(DefaultMessage.java:94)
    at org.apache.camel.impl.DefaultUnitOfWork.(DefaultUnitOfWork.java:115)
    at org.apache.camel.impl.DefaultUnitOfWork.(DefaultUnitOfWork.java:75)
    at org.apache.camel.impl.DefaultUnitOfWorkFactory.createUnitOfWork(DefaultUnitOfWorkFactory.java:34)
    at org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.createUnitOfWork(CamelInternalProcessor.java:695)
    at org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.before(CamelInternalProcessor.java:663)
    at org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.before(CamelInternalProcessor.java:634)
    at org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:149)
    at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:97)
    at org.apache.camel.component.jms.EndpointMessageListener.onMessage(EndpointMessageListener.java:113)
    at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:736)
    at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:696)
    at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:674)
    at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:318)
    at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)
    at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1189)
    at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1179)
    at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1076)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)
Caused by: javax.jms.MessageFormatException: JMS-117: Conversion failed - invalid property type
    at oracle.jms.AQjmsError.throwMsgFormatEx(AQjmsError.java:452)
    at oracle.jms.AQjmsMessage.getObjectProperty(AQjmsMessage.java:1584)
    at org.apache.camel.component.jms.JmsMessageHelper.getProperty(JmsMessageHelper.java:118)
    at org.apache.camel.component.jms.JmsBinding.extractHeadersFromJms(JmsBinding.java:214)
    ... 25 common frames omitted

If I understand the stacktrace correctly it is the oracle.jms api that is missing a header JMSXGroupSeq which is not unlikely since the counterpart isn't using the oracle jms api to create the message. Neither him nor me is able to view the actual queue (it's on our mutual client's side) so I have no means of checking what headers are actually in place.

Using a custom headerFilterStrategy is no help since the error is thrown right before I get to the headerFilterStrategy. See below extract from org.apache.camel.component.jms.JmsBinding method extractHeadersFromJms. The error is thrown from JmsMessageHelper.getProperty()

Object value = JmsMessageHelper.getProperty(jmsMessage, name);
if (headerFilterStrategy != null 
 && headerFilterStrategy.applyFilterToExternalHeaders(name, value, exchange)) {
 continue;
 }

So my first question is...

Is it possible to receive the message that may be "invalid" - can I make camel and the oracle api ignore missing/invalid headers?

Second question... why is Oracle acknowledging the message as if everything went fine when in fact the message was never successfully recreated on receiver side?


Solution

  • Due to the error message "Conversion failed", I suspect that the JMS property JMSXGroupSeq has an invalid type.

    Since Camel simply tries to read this value in JmsMessageHelper.getProperty I guess there must be some very strange value in this property.

    Have you tried to peek inside such a message with tools like JMS Toolbox? If you see the property value you could perhaps advise the producer how to fix it.

    To answer your questions:

    Is it possible to receive the message that may be "invalid"?

    With Camel, I don't think so. Camel excels in making your live convenient and therefore does all the low-level stuff and gives you a nice Exchange object with Messages in it.

    If an Exception is thrown inside this part, I guess you are out of luck because, as you already mention, it is thrown before you can intervene. This implicitly shows how rare such cases occur and how strange this property value must be.

    However, you can of course use something else to consume the message. Something that does not try to read all headers automatically, but does at least the low-level work of JMS. Perhaps Spring JMS would be a candidate. Camel JMS uses Spring JMS under the hood.

    why is Oracle acknowledging the message?

    For the property JMSXGroupSeq the JMS Docs say

    JMSXGroupID and JMSXGroupSeq are standard properties that clients should use if they want to group messages. All providers must support them. Unless specifically noted, the values and semantics of the JMSX properties are undefined.

    If the values are undefined, there is nothing a Broker can use to validate.