Prathiba,
Your ExceptionListener call setError() regardless of the current state
of your message exchange. This causes the MessageExchange status to
become ERROR. If you do this on an ACTIVE exchange before it is
actually sent to the target component, it causes the exception you see
in the logging (illegal exchange status: error).
You can solve this by adding a test for status in your
ExceptionListener's exchangeSent() method
if (message.getStatus() == ExchangeStatus.ERROR) {
//go ahead and replace the existing error message with your own
}
This way, you will only improve the exception message when the
MessageExchange status already is ERROR (so there is an exception), not
touching other (ACTIVE/DONE) exchanges. You might have to do something
similar later on for cases where the status is DONE if the exchange has
a 'fault' normalized message.
Does this fix your problem?
Gert
pratibhaG wrote:
There are differences between the logs at various places:
here are the logs which I get after the zip file of my example gets deployed
in SMX-HOME/hotdeploy
(I am using servicemix3.2.1 and it has camel 1.2)
This is what I got when I had no listener:
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-7:7
status: Active
role: provider
service: {http://esbinaction.com/errorhandling}errorHandlerDSL
endpoint: camel192-168-2-64-11a193645af-21-6
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - CamelJbiComponent - Received exchange: status: Active,
role: provider
DEBUG - CamelJbiComponent - Retrieved correlation id:
ID:192.168.2.64-11a193645af-7:7
DEBUG - CamelJbiEndpoint - Received exchange: InOnly[
id: ID:192.168.2.64-11a193645af-7:7
status: Active
role: provider
service: {http://esbinaction.com/errorhandling}errorHandlerDSL
endpoint: camel192-168-2-64-11a193645af-21-6
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - DeliveryChannelImpl - SendSync
ID:192.168.2.64-11a193645af-4:29 in DeliveryChannel{servicemix-camel}
DEBUG - SedaFlow - Called Flow send
DEBUG - DeliveryChannelImpl - Waiting for exchange
ID:192.168.2.64-11a193645af-4:29 (157d6e) to be answered in
DeliveryChannel{servicemix-camel} from sendSync
DEBUG - ServerSessionImpl:2 - run loop end
DEBUG - ServerSessionPoolImpl - Session returned to pool:
ServerSessionImpl:2
DEBUG - ServerSessionImpl:2 - Run finished
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-4:29
status: Active
role: provider
service: {http://esbinaction.com/errorhandling}errorComponent
endpoint: errorEndpoint
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - BeanComponent - Received exchange: status: Active,
role: provider
DEBUG - BeanComponent - Retrieved correlation id: null
DEBUG - DeliveryChannelImpl - Send
ID:192.168.2.64-11a193645af-4:29 in DeliveryChannel{servicemix-bean}
DEBUG - SedaFlow - Called Flow send
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-4:29
status: Error
role: consumer
service: {http://esbinaction.com/errorhandling}errorComponent
endpoint: errorEndpoint
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
error: java.lang.NullPointerException: myexception
]
DEBUG - DeliveryChannelImpl - Notifying exchange
ID:192.168.2.64-11a193645af-4:29(157d6e) in
DeliveryChannel{servicemix-camel} from processInboundSynchronousExchange
DEBUG - DeliveryChannelImpl - Notified:
ID:192.168.2.64-11a193645af-4:29(157d6e) in
DeliveryChannel{servicemix-camel} from sendSync
ERROR - DeadLetterChannel - On delivery attempt: 0 caught:
java.lang.NullPointerException: myexception
java.lang.NullPointerException: myexception
at
errorhandling.ErrorComponent.onMessageExchange(ErrorComponent.java:19)
at
org.apache.servicemix.bean.BeanEndpoint.onProviderExchange(BeanEndpoint.java:235)
at
org.apache.servicemix.bean.BeanEndpoint.process(BeanEndpoint.java:211)
at
org.apache.servicemix.common.AsyncBaseLifeCycle.doProcess(AsyncBaseLifeCycle.java:538)
at
org.apache.servicemix.common.AsyncBaseLifeCycle.processExchange(AsyncBaseLifeCycle.java:490)
at
org.apache.servicemix.common.BaseLifeCycle.onMessageExchange(BaseLifeCycle.java:46)
at
org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.processInBound(DeliveryChannelImpl.java:610)
at
org.apache.servicemix.jbi.nmr.flow.AbstractFlow.doRouting(AbstractFlow.java:170)
at
org.apache.servicemix.jbi.nmr.flow.seda.SedaFlow.doRouting(SedaFlow.java:167)
at
org.apache.servicemix.jbi.nmr.flow.seda.SedaQueue$1.run(SedaQueue.java:134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
DEBUG - DeliveryChannelImpl - SendSync
ID:192.168.2.64-11a193645af-4:30 in DeliveryChannel{servicemix-camel}
DEBUG - SedaFlow - Called Flow send
DEBUG - DeliveryChannelImpl - Waiting for exchange
ID:192.168.2.64-11a193645af-4:30 (1038c21) to be answered in
DeliveryChannel{servicemix-camel} from sendSync
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-4:30
status: Active
role: provider
service: {http://esbinaction.com/errorhandling}errorStorageService
endpoint: errorStorageEndpoint
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - JmsComponent - Received exchange: status: Active,
role: provider
DEBUG - JmsComponent - Retrieved correlation id: null
DEBUG - ActiveMQSession - Sending message:
ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId =
ID:gpratibha.site-46546-1211603803334-3:210:1:1:1, originalDestination =
null, originalTransactionId = null, producerId =
ID:gpratibha.site-46546-1211603803334-3:210:1:1, destination =
queue://tutorial.camel.queue3, transactionId = null, expiration = 0,
timestamp = 1211605045986, arrival = 0, correlationId = null, replyTo =
null, persistent = true, type = null, priority = 4, groupID = null,
groupSequence = 0, targetConsumerId = null, compressed = false, userID =
null, content = null, marshalledProperties = null, dataStructure = null,
redeliveryCounter = 0, size = 0, properties =
{MimeContentType=text/xml;charset=UTF-8}, readOnlyProperties = true,
readOnlyBody = true, droppable = false, text = <?xml version='1.0'
encoding='UTF-8'?><message>Hello world!</message>}
DEBUG - JournalMessageStore - Journalled message add for:
ID:gpratibha.site-46546-1211603803334-3:210:1:1:1, at: 1:13322597
DEBUG - queue3 - No subscriptions registered, will
not dispatch message at this time.
DEBUG - DeliveryChannelImpl - Send
ID:192.168.2.64-11a193645af-4:30 in DeliveryChannel{servicemix-jms}
DEBUG - SedaFlow - Called Flow send
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-4:30
status: Done
role: consumer
service: {http://esbinaction.com/errorhandling}errorStorageService
endpoint: errorStorageEndpoint
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - DeliveryChannelImpl - Notifying exchange
ID:192.168.2.64-11a193645af-4:30(1038c21) in
DeliveryChannel{servicemix-camel} from processInboundSynchronousExchange
DEBUG - DeliveryChannelImpl - Notified:
ID:192.168.2.64-11a193645af-4:30(1038c21) in
DeliveryChannel{servicemix-camel} from sendSync
DEBUG - DeliveryChannelImpl - Send
ID:192.168.2.64-11a193645af-7:7 in DeliveryChannel{servicemix-camel}
DEBUG - SedaFlow - Called Flow send
DEBUG - SedaQueue -
[EMAIL PROTECTED] dequeued
exchange: InOnly[
id: ID:192.168.2.64-11a193645af-7:7
status: Done
role: consumer
service: {http://esbinaction.com/errorhandling}errorHandlerDSL
endpoint: camel192-168-2-64-11a193645af-21-6
in: <?xml version="1.0" encoding="UTF-8"?><message>Hello world!</message>
]
DEBUG - JmsComponent - Received exchange: status: Done,
role: consumer
DEBUG - JmsComponent - Retrieved correlation id:
ID:192.168.2.64-11a193645af-7:7
This what I got when I had listener
DEBUG - ServerSessionPoolImpl - ServerSession requested.
DEBUG - AbstractRegion - Removing consumer:
ID:gpratibha.site-60634-1211605839251-3:7:-1:15
DEBUG - ServerSessionPoolImpl - Using idle session:
ServerSessionImpl:1
DEBUG - ServerSessionImpl:1 - Starting run.
DEBUG - ServerSessionImpl:1 - Running
DEBUG - ServerSessionImpl:1 - run loop start
DEBUG - JmsComponent - Created correlation id:
ID:192.168.2.64-11a1956b739-7:0
ERROR - MultiplexingConsumerProcessor - Error while handling jms message
javax.jbi.messaging.MessagingException: illegal exchange status: error
at
org.apache.servicemix.jbi.messaging.MessageExchangeImpl.handleSend(MessageExchangeImpl.java:629)
at
org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.doSend(DeliveryChannelImpl.java:385)
at
org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.send(DeliveryChannelImpl.java:431)
at
org.apache.servicemix.common.EndpointDeliveryChannel.send(EndpointDeliveryChannel.java:79)
at
org.apache.servicemix.jms.multiplexing.MultiplexingConsumerProcessor$1.run(MultiplexingConsumerProcessor.java:93)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
DEBUG - AbstractRegion - Adding consumer:
ID:gpratibha.site-60634-1211605839251-3:40:-1:2
DEBUG - ServerSessionImpl:1 - run loop end
DEBUG - ServerSessionPoolImpl - Session returned to pool:
ServerSessionImpl:1
DEBUG - ServerSessionImpl:1 - Run finished
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - Transport - Transport failed:
java.io.EOFException
java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:358)
at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267)
at
org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:156)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:136)
at java.lang.Thread.run(Thread.java:595)
DEBUG - TransportConnection - Stopping connection:
/127.0.0.1:35782
DEBUG - TransportConnection - Stopped connection:
/127.0.0.1:35782
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
DEBUG - JournalPersistenceAdapter - Checkpoint started.
DEBUG - JournalPersistenceAdapter - Marking journal at: 1:13323221
DEBUG - JDBCPersistenceAdapter - Cleaning up old messages.
DEBUG - DefaultJDBCAdapter - Executing SQL: DELETE FROM
ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION<?) OR ID <= ( SELECT
min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER)
DEBUG - DefaultJDBCAdapter - Deleted 0 old message(s).
DEBUG - JDBCPersistenceAdapter - Cleanup done.
DEBUG - JournalPersistenceAdapter - Checkpoint done.
I guess the problem arises here:
ERROR - MultiplexingConsumerProcessor - Error while handling jms message
javax.jbi.messaging.MessagingException: illegal exchange status: error
at
org.apache.servicemix.jbi.messaging.MessageExchangeImpl.handleSend(MessageExchangeImpl.java:629)
at
org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.doSend(DeliveryChannelImpl.java:385)
at
org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.send(DeliveryChannelImpl.java:431)
at
org.apache.servicemix.common.EndpointDeliveryChannel.send(EndpointDeliveryChannel.java:79)
at
org.apache.servicemix.jms.multiplexing.MultiplexingConsumerProcessor$1.run(MultiplexingConsumerProcessor.java:93)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Any Idea?
-Pratibha
